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:21
Elapsed6m8s
Revisione6369b1b1ab0694bea1ed5684eed83e8b2f74710
Refs 4920

No Test Failures!


Error lines from build-log.txt

... skipping 781 lines ...
I0712 16:24:35.774856    8687 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:24:36.344236    8687 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" 
•I0712 16:24:36.354938    8687 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.914 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.91s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	76.138s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== 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.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0712 16:24:06.808687   10745 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0712 16:24:06.808735   10745 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0712 16:24:06.809141   10745 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:24:06.809187   10745 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:24:06.809306   10745 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0712 16:24:06.809352   10745 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
2021/07/12 16:24:07 http: TLS handshake error from 127.0.0.1:58618: 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:24:07.106495   10745 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:24:07.109666   10745 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:24:07.151108   10745 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:24:07.152952   10745 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:24:07.153306   10745 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:24:07.153845   10745 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:24:07.417340   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0712 16:24:07.522360   10745 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:24:07.536818   10745 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0712 16:24:07.536897   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0712 16:24:07.667807   10745 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0712 16:24:07.667910   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0712 16:24:07.768706   10745 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4" "noderef"="node-1"
E0712 16:24:07.780458   10745 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:24:07.780513   10745 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:24:07.822775   10745 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4" "noderef"="node-1"
E0712 16:24:07.945497   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-tpp2p\" in namespace \"test-machine-watches-lrjg4\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4"
E0712 16:24:08.952791   10745 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-tpp2p\" in namespace \"test-machine-watches-lrjg4\", requeuing: requeue in 1s"  
E0712 16:24:08.963221   10745 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-tpp2p\" in namespace \"test-machine-watches-lrjg4\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-tpp2p\" in namespace \"test-machine-watches-lrjg4\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4"
--- PASS: TestWatches (1.84s)
=== 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:24:09.087308   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-tpq9k" "namespace"="test-machine-watches-lrjg4" "count"=1
I0712 16:24:09.087420   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-tpq9k" "namespace"="test-machine-watches-lrjg4" "descendants"="Worker machines: machine-created-tpp2p" "indirect descendants count"=0
I0712 16:24:09.131647   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-tpq9k" "namespace"="test-machine-watches-lrjg4" "count"=1
I0712 16:24:09.131713   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-tpq9k" "namespace"="test-machine-watches-lrjg4" "descendants"="Worker machines: machine-created-tpp2p" "indirect descendants count"=0
I0712 16:24:09.965005   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-tpq9k" "machine"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"a136cfd6-440d-4acb-94b9-e7ebcd340a7d","apiVersion":"v1"}
E0712 16:24:10.031998   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-tpp2p\" not found" "controller"="machine" "name"="machine-created-tpp2p" "namespace"="test-machine-watches-lrjg4"
E0712 16:24:11.166801   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-98csw\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-vx8t2\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-vx8t2: secrets \"machine-reconcile-vx8t2-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-98csw" "namespace"="default"
I0712 16:24:12.167724   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vx8t2" "machine"="machine-created-98csw" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:24:12.254636   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vx8t2" "machine"="machine-created-98csw" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:24:12.309304   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-vx8t2" "machine"="machine-created-98csw" "namespace"="default" "cause"="noderef is nil" "node"=null
E0712 16:24:12.384791   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-98csw\" not found" "controller"="machine" "name"="machine-created-98csw" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.41s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.41s)
=== 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.01s)
    --- PASS: TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one (0.00s)
    --- PASS: TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer (0.00s)
=== RUN   TestMachineOwnerReference
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0712 16:24:12.415689   10745 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:24:12.415991   10745 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
E0712 16:24:12.438900   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-vx8t2\" not found" "controller"="cluster" "name"="machine-reconcile-vx8t2" "namespace"="default"
I0712 16:24:12.443256   10745 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:24:12.447754   10745 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0712 16:24:12.466446   10745 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:24:12.466933   10745 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.07s)
... skipping 122 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/scaling_up (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0712 16:24:12.719217   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fm8g8" "namespace"="test-mhc-hxjnl" 
E0712 16:24:12.800203   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-t2sg7\" not found"  "cluster"="test-mhc-hxjnl/test-cluster-t2sg7"
I0712 16:24:12.801846   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0712 16:24:12.909200   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-fm8g8\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-fm8g8\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-fm8g8" "namespace"="test-mhc-hxjnl"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0712 16:24:13.909517   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-wdkfx" "namespace"="test-mhc-6wwjj" 
I0712 16:24:13.909622   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fm8g8" "namespace"="test-mhc-hxjnl" 
I0712 16:24:13.909651   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8bfrq" "namespace"="test-mhc-qh7rv" 
I0712 16:24:13.909676   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljtzj" "namespace"="test-mhc-vtmqv" 
I0712 16:24:13.925538   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:14.044769   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljtzj" "namespace"="test-mhc-vtmqv" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0712 16:24:14.060696   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ljtzj" "namespace"="test-mhc-vtmqv" 
E0712 16:24:14.078773   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-vtmqv/test-cluster-vbkwq"
E0712 16:24:14.080913   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-vbkwq\" not found" "controller"="cluster" "name"="test-cluster-vbkwq" "namespace"="test-mhc-vtmqv"
I0712 16:24:14.093079   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-28xpl" "namespace"="test-mhc-hjrgn" 
I0712 16:24:14.116919   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:14.144203   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-28xpl" "namespace"="test-mhc-hjrgn" 
E0712 16:24:14.198300   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hjrgn/test-cluster-xmpxk"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0712 16:24:14.204030   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-28xpl" "namespace"="test-mhc-hjrgn" 
I0712 16:24:14.222279   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
inframachine created: test-mhc-machine-infra-twf6m
I0712 16:24:14.255346   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-pktmf
I0712 16:24:14.359489   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-pktmf/"
node created: test-mhc-node-xhkt5
E0712 16:24:14.373649   10745 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-xhkt5"
E0712 16:24:14.373853   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xhkt5, got []"  "node"="test-mhc-node-xhkt5"
inframachine created: test-mhc-machine-infra-95dpl
I0712 16:24:14.394483   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
machine created: test-mhc-machine-v4znj
I0712 16:24:14.408958   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.415339   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.416409   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
... skipping 75 lines ...
I0712 16:24:14.590965   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.592251   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.593551   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.594607   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.595631   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.629395   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.629941   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
I0712 16:24:14.671301   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.671688   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
I0712 16:24:14.675132   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.675564   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
I0712 16:24:14.683148   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.683552   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
I0712 16:24:14.710444   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.711226   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
I0712 16:24:14.734238   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.734692   10745 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-b2w7t/test-mhc-qsmcz/test-mhc-machine-v4znj/"
E0712 16:24:14.735333   10745 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-pqd2m"
E0712 16:24:14.735538   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pqd2m, got []"  "node"="test-mhc-node-pqd2m"
node created: test-mhc-node-pqd2m
I0712 16:24:14.743669   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.764865   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.766302   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:14.778717   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.782106   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:14.782573   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-b2w7t/test-mhc-qsmcz/test-mhc-machine-pktmf/"
E0712 16:24:14.818652   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-b2w7t/test-cluster-5nfx2"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
inframachine created: test-mhc-machine-infra-9jj6w
machine created: test-mhc-machine-qd4pt
E0712 16:24:14.932535   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
E0712 16:24:15.012470   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-qsmcz\" not found" "controller"="machinehealthcheck" "name"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t"
E0712 16:24:15.107461   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-lrjg4/machine-reconcile-tpq9k"
E0712 16:24:15.932932   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:16.012762   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.033702   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:16.059843   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qsmcz" "namespace"="test-mhc-b2w7t" 
I0712 16:24:16.059908   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.060956   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.062962   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 405 lines ...
I0712 16:24:16.941314   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.943863   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.944882   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.946504   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.948220   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.949714   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.950101   10745 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-glvtm/test-mhc-d8vkg/test-mhc-machine-qd4pt/"
E0712 16:24:16.950465   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:16.985282   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:16.985635   10745 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-glvtm/test-mhc-d8vkg/test-mhc-machine-qd4pt/"
node created: test-mhc-node-w2bcx
E0712 16:24:16.995753   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w2bcx, got []"  "node"="test-mhc-node-w2bcx"
I0712 16:24:17.005655   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
inframachine created: test-mhc-machine-infra-4k5ws
machine created: test-mhc-machine-npqfb
I0712 16:24:17.054150   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.061170   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.062309   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 270 lines ...
I0712 16:24:17.950081   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.952358   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.954599   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.956732   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.958914   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.961058   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
E0712 16:24:17.962934   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:17.963323   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.965479   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.967635   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.969809   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.971987   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:17.974302   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 364 lines ...
I0712 16:24:18.993890   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:18.996116   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.001347   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.002603   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.003662   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.004773   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
E0712 16:24:19.005392   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:19.021942   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.024414   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.026766   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.029084   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.031291   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:19.033687   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 330 lines ...
I0712 16:24:20.014005   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.016209   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.018188   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.019369   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.021514   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.023070   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.023423   10745 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-glvtm/test-mhc-d8vkg/test-mhc-machine-npqfb/"
E0712 16:24:20.024337   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:20.033569   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:20.034073   10745 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-glvtm/test-mhc-d8vkg/test-mhc-machine-npqfb/"
E0712 16:24:20.068151   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-r988q, got []"  "node"="test-mhc-node-r988q"
node created: test-mhc-node-r988q
I0712 16:24:20.075990   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
inframachine created: test-mhc-machine-infra-w4prs
I0712 16:24:20.094734   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
machine created: test-mhc-machine-psjw9
I0712 16:24:20.100581   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 269 lines ...
I0712 16:24:21.023626   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.026105   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.028586   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.036735   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.039349   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.041904   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
E0712 16:24:21.044441   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:21.052727   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.054757   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.056688   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.058537   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.061306   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:21.062929   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 266 lines ...
I0712 16:24:22.060696   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.063464   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.065653   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.069484   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.077680   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.084738   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
E0712 16:24:22.087330   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:22.088159   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.090323   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.091462   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.093323   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.095036   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:22.096350   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
... skipping 269 lines ...
I0712 16:24:23.082113   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.085408   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.088174   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.092006   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.103573   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.106554   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.108837   10745 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-glvtm/test-mhc-d8vkg/test-mhc-machine-psjw9/"
E0712 16:24:23.113485   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
node created: test-mhc-node-mg8nf
E0712 16:24:23.114927   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mg8nf, got []"  "node"="test-mhc-node-mg8nf"
Cleaning up nodes, machines and infra machines.
I0712 16:24:23.125375   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-d8vkg" "namespace"="test-mhc-glvtm" 
I0712 16:24:23.125911   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-glvtm/test-mhc-d8vkg/test-mhc-machine-psjw9/"
Cleaning up nodes, machines and infra machines.
I0712 16:24:23.181162   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-76w24" "namespace"="test-mhc-glvtm" "count"=2
I0712 16:24:23.181247   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-76w24" "namespace"="test-mhc-glvtm" "descendants"="Worker machines: test-mhc-machine-qd4pt,test-mhc-machine-npqfb,test-mhc-machine-psjw9" "indirect descendants count"=1
I0712 16:24:23.187916   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-76w24" "namespace"="test-mhc-glvtm" "count"=2
I0712 16:24:23.187992   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-76w24" "namespace"="test-mhc-glvtm" "descendants"="Worker machines: test-mhc-machine-qd4pt,test-mhc-machine-npqfb,test-mhc-machine-psjw9" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
... skipping 7 lines ...
I0712 16:24:23.428490   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:23.472206   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:23.553491   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:23.714437   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:24.035536   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:24.114018   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-76w24" "machine"="test-mhc-machine-npqfb" "namespace"="test-mhc-glvtm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-r988q"}
E0712 16:24:24.159598   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-npqfb\" not found" "controller"="machine" "name"="test-mhc-machine-npqfb" "namespace"="test-mhc-glvtm"
I0712 16:24:24.676852   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:25.160237   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:25.959200   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:26.160785   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-76w24" "machine"="test-mhc-machine-psjw9" "namespace"="test-mhc-glvtm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mg8nf"}
E0712 16:24:26.217305   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-psjw9\" not found" "controller"="machine" "name"="test-mhc-machine-psjw9" "namespace"="test-mhc-glvtm"
I0712 16:24:27.217804   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-76w24" "machine"="test-mhc-machine-qd4pt" "namespace"="test-mhc-glvtm" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-w2bcx"}
E0712 16:24:27.280672   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qd4pt\" not found" "controller"="machine" "name"="test-mhc-machine-qd4pt" "namespace"="test-mhc-glvtm"
E0712 16:24:28.201471   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-glvtm/test-cluster-76w24"
E0712 16:24:28.281048   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:28.520210   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.290308   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.303625   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:29.310832   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:29.333300   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
node created: test-mhc-node-n2658
E0712 16:24:29.390602   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-n2658, got []"  "node"="test-mhc-node-n2658"
I0712 16:24:29.399458   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
inframachine created: test-mhc-machine-infra-l5gfj
machine created: test-mhc-machine-q44zg
I0712 16:24:29.423614   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.434786   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.439958   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.461939   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.503205   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.584463   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:29.745879   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:30.069980   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:30.316866   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:30.712031   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.329857   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.337646   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.352869   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.365978   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.379696   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:31.385868   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:31.409675   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:31.437768   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-7crmf, got []"  "node"="test-mhc-node-7crmf"
node created: test-mhc-node-7crmf
I0712 16:24:31.448551   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.450247   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
inframachine created: test-mhc-machine-infra-2kbvk
I0712 16:24:31.462345   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
machine created: test-mhc-machine-j24dx
I0712 16:24:31.479810   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.495928   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:31.993506   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:32.386161   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:33.407270   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.425108   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.432830   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.445514   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.451971   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.459443   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
E0712 16:24:33.462804   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:33.462850   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.484973   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
node created: test-mhc-node-9k2s9
E0712 16:24:33.503049   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9k2s9, got []"  "node"="test-mhc-node-9k2s9"
I0712 16:24:33.509141   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:33.523729   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.525826   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:33.587407   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:33.590909   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-srqpz" "namespace"="test-mhc-fj2nf" "count"=2
I0712 16:24:33.590993   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-srqpz" "namespace"="test-mhc-fj2nf" "descendants"="Worker machines: test-mhc-machine-mhmkf,test-mhc-machine-q44zg,test-mhc-machine-j24dx" "indirect descendants count"=1
I0712 16:24:33.597546   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-srqpz" "namespace"="test-mhc-fj2nf" "count"=2
I0712 16:24:33.597632   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-srqpz" "namespace"="test-mhc-fj2nf" "descendants"="Worker machines: test-mhc-machine-mhmkf,test-mhc-machine-q44zg,test-mhc-machine-j24dx" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
E0712 16:24:33.623127   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-bgwmt\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-bgwmt\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf"
inframachine created: test-mhc-machine-infra-4ntbc
machine created: test-mhc-machine-f78v9
E0712 16:24:34.463846   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:34.623436   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bgwmt" "namespace"="test-mhc-fj2nf" 
I0712 16:24:34.623553   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:34.638481   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:34.769574   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:35.464412   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-srqpz" "machine"="test-mhc-machine-mhmkf" "namespace"="test-mhc-fj2nf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-n2658"}
E0712 16:24:35.510074   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mhmkf\" not found" "controller"="machine" "name"="test-mhc-machine-mhmkf" "namespace"="test-mhc-fj2nf"
I0712 16:24:36.510682   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-srqpz" "machine"="test-mhc-machine-q44zg" "namespace"="test-mhc-fj2nf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-7crmf"}
E0712 16:24:36.572532   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q44zg\" not found" "controller"="machine" "name"="test-mhc-machine-q44zg" "namespace"="test-mhc-fj2nf"
I0712 16:24:37.573038   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-srqpz" "machine"="test-mhc-machine-j24dx" "namespace"="test-mhc-fj2nf" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9k2s9"}
E0712 16:24:37.617406   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j24dx\" not found" "controller"="machine" "name"="test-mhc-machine-j24dx" "namespace"="test-mhc-fj2nf"
E0712 16:24:38.610205   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fj2nf/test-cluster-srqpz"
I0712 16:24:38.626193   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:38.631866   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
E0712 16:24:38.633167   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
E0712 16:24:38.685458   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zhdq9, got []"  "node"="test-mhc-node-zhdq9"
node created: test-mhc-node-zhdq9
I0712 16:24:38.693494   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
inframachine created: test-mhc-machine-infra-rl7j8
machine created: test-mhc-machine-m7jpk
I0712 16:24:38.714857   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:38.721020   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
E0712 16:24:39.633586   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:40.649620   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.662385   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.680210   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.690974   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.708449   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.727346   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.744698   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.768452   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.778605   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.792294   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.810863   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
node created: test-mhc-node-4fjqq
E0712 16:24:40.825804   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4fjqq, got []"  "node"="test-mhc-node-4fjqq"
I0712 16:24:40.833618   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
inframachine created: test-mhc-machine-infra-llkpx
I0712 16:24:40.853060   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
machine created: test-mhc-machine-rphnm
I0712 16:24:40.859225   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.870582   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
... skipping 6 lines ...
I0712 16:24:40.960540   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.966273   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:40.980611   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4zrfj" "machine"="test-mhc-machine-rphnm" "namespace"="test-mhc-fwffz" "cause"="noderef is nil" "node"=null
I0712 16:24:40.981358   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.988369   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:40.990080   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fwffz/test-mhc-9zzhn/test-mhc-machine-f78v9/"
I0712 16:24:41.028765   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:41.029389   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fwffz/test-mhc-9zzhn/test-mhc-machine-f78v9/"
I0712 16:24:41.029810   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fwffz/test-mhc-9zzhn/test-mhc-machine-m7jpk/"
E0712 16:24:41.046678   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-rphnm\" not found" "controller"="machine" "name"="test-mhc-machine-rphnm" "namespace"="test-mhc-fwffz"
I0712 16:24:41.049827   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4zrfj" "namespace"="test-mhc-fwffz" "count"=2
I0712 16:24:41.049927   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4zrfj" "namespace"="test-mhc-fwffz" "descendants"="Worker machines: test-mhc-machine-m7jpk,test-mhc-machine-f78v9" "indirect descendants count"=0
I0712 16:24:41.054329   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:41.054844   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fwffz/test-mhc-9zzhn/test-mhc-machine-f78v9/"
I0712 16:24:41.055281   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-fwffz/test-mhc-9zzhn/test-mhc-machine-m7jpk/"
I0712 16:24:41.056795   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-4zrfj" "namespace"="test-mhc-fwffz" "count"=2
I0712 16:24:41.056845   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4zrfj" "namespace"="test-mhc-fwffz" "descendants"="Worker machines: test-mhc-machine-f78v9,test-mhc-machine-m7jpk" "indirect descendants count"=0
E0712 16:24:41.061041   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-9zzhn\" not found" "controller"="machinehealthcheck" "name"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz"
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-rdcw7
machine created: test-mhc-machine-8ltcc
I0712 16:24:42.047248   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4zrfj" "machine"="test-mhc-machine-f78v9" "namespace"="test-mhc-fwffz" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-zhdq9"}
I0712 16:24:42.061385   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-9zzhn" "namespace"="test-mhc-fwffz" 
I0712 16:24:42.061470   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.084422   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:42.111065   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.112149   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
E0712 16:24:42.112184   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-f78v9\" not found" "controller"="machine" "name"="test-mhc-machine-f78v9" "namespace"="test-mhc-fwffz"
I0712 16:24:42.113885   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.115523   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.117198   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.118802   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.120545   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:42.122878   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
... skipping 470 lines ...
I0712 16:24:43.144748   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.146921   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.148973   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.150836   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.152674   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.157859   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
E0712 16:24:43.161452   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-m7jpk\" not found" "controller"="machine" "name"="test-mhc-machine-m7jpk" "namespace"="test-mhc-fwffz"
I0712 16:24:43.161544   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.163294   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.164995   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.166659   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.168264   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:43.169918   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
... skipping 451 lines ...
I0712 16:24:44.167699   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.169431   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.170004   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.171092   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.172816   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.174561   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.174812   10745 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-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/"
E0712 16:24:44.174872   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:44.186802   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.187127   10745 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-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/"
node created: test-mhc-node-95sfc
E0712 16:24:44.233854   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-95sfc, got []"  "node"="test-mhc-node-95sfc"
E0712 16:24:44.233860   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-95sfc, got []"  "node"="test-mhc-node-95sfc"
I0712 16:24:44.242286   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.258331   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.269902   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.270146   10745 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-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/test-mhc-node-95sfc"
I0712 16:24:44.290755   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.291154   10745 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-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/test-mhc-node-95sfc"
I0712 16:24:44.291891   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.292182   10745 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-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/test-mhc-node-95sfc"
Cleaning up nodes, machines and infra machines.
I0712 16:24:44.305133   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.305498   10745 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-ssc9c/test-mhc-l9v88/test-mhc-machine-8ltcc/"
I0712 16:24:44.325199   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-t6gzr" "namespace"="test-mhc-ssc9c" "descendants"="Worker machines: test-mhc-machine-8ltcc" "indirect descendants count"=1
I0712 16:24:44.329580   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-t6gzr" "namespace"="test-mhc-ssc9c" "descendants"="Worker machines: test-mhc-machine-8ltcc" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0712 16:24:44.455219   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-l9v88" "namespace"="test-mhc-ssc9c" 
I0712 16:24:44.526523   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" "creating"=1 "need"=1
I0712 16:24:44.526563   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:44.537390   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-mp85j-6rlwd\"" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:44.616586   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:44.657032   10745 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:44.659178   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:24:44.792547   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:44.793280   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
E0712 16:24:45.175342   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:45.792851   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
E0712 16:24:46.071723   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fwffz/test-cluster-4zrfj"
I0712 16:24:46.175854   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-t6gzr" "machine"="test-mhc-machine-8ltcc" "namespace"="test-mhc-ssc9c" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-95sfc"}
E0712 16:24:46.221575   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8ltcc\" not found" "controller"="machine" "name"="test-mhc-machine-8ltcc" "namespace"="test-mhc-ssc9c"
I0712 16:24:46.793842   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.232693   10745 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.232852   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.237910   10745 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.238095   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.250703   10745 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
... skipping 5 lines ...
I0712 16:24:47.274503   10745 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.274557   10745 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:47.794887   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:48.272603   10745 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:48.272656   10745 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.000664   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.001090   10745 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-npxz6/test-mhc-xkc5m/mhc-ms-mp85j-6rlwd/"
I0712 16:24:49.020972   10745 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.029877   10745 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.029931   10745 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.031875   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.032203   10745 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-npxz6/test-mhc-xkc5m/mhc-ms-mp85j-6rlwd/"
I0712 16:24:49.036798   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.037147   10745 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-npxz6/test-mhc-xkc5m/mhc-ms-mp85j-6rlwd/"
I0712 16:24:49.037582   10745 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.046778   10745 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.046828   10745 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.081699   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-zgnzw" "namespace"="test-mhc-npxz6" "count"=1
I0712 16:24:49.081763   10745 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-zgnzw" "namespace"="test-mhc-npxz6" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-mp85j"
I0712 16:24:49.085407   10745 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" "machine"="mhc-ms-mp85j-6rlwd"
I0712 16:24:49.086721   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xkc5m" "namespace"="test-mhc-npxz6" 
I0712 16:24:49.089728   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zgnzw" "namespace"="test-mhc-npxz6" "descendants"="Machine sets: mhc-ms-mp85j;Worker machines: mhc-ms-mp85j-6rlwd" "indirect descendants count"=1
I0712 16:24:49.091711   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zgnzw" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" "cause"="cluster is being deleted" "node"=null
I0712 16:24:49.094836   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zgnzw" "namespace"="test-mhc-npxz6" "descendants"="Worker machines: mhc-ms-mp85j-6rlwd" "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
E0712 16:24:49.106323   10745 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-mp85j\" not found" "machineset"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6" 
E0712 16:24:49.106408   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"mhc-ms-mp85j\" not found" "controller"="machineset" "name"="mhc-ms-mp85j" "namespace"="test-mhc-npxz6"
I0712 16:24:49.277283   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zgnzw" "machine"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6" "cause"="cluster is being deleted" "node"=null
I0712 16:24:49.288596   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
inframachine created: test-mhc-machine-infra-sg7g6
I0712 16:24:49.310037   10745 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-htvw2
E0712 16:24:49.330240   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-mp85j-6rlwd\" not found" "controller"="machine" "name"="mhc-ms-mp85j-6rlwd" "namespace"="test-mhc-npxz6"
E0712 16:24:49.410675   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-ssc9c/test-cluster-t6gzr"
I0712 16:24:49.431256   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:49.440540   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:49.442670   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:49.444250   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:49.445501   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:49.446603   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
... skipping 414 lines ...
I0712 16:24:50.316707   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.318604   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.321153   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.322996   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.324821   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.326527   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
E0712 16:24:50.333022   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
I0712 16:24:50.333110   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.336013   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.337884   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.339635   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.341390   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:50.343534   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
... skipping 468 lines ...
I0712 16:24:51.320141   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.321942   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.323673   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.332874   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.337849   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.344463   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
E0712 16:24:51.346532   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
I0712 16:24:51.348186   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.398779   10745 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-htvw2" "target"="test-mhc-gt2kk/test-mhc-x59fx/test-mhc-machine-htvw2/"
I0712 16:24:51.411099   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
E0712 16:24:51.444962   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2f7z5, got []"  "node"="test-mhc-node-2f7z5"
E0712 16:24:51.445234   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2f7z5, got []"  "node"="test-mhc-node-2f7z5"
node created: test-mhc-node-2f7z5
I0712 16:24:51.453048   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.492456   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.499669   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.502929   10745 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-htvw2" "target"="test-mhc-gt2kk/test-mhc-x59fx/test-mhc-machine-htvw2/test-mhc-node-2f7z5"
I0712 16:24:51.520857   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.523694   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:51.548515   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.551260   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
I0712 16:24:51.556230   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-x59fx" "namespace"="test-mhc-gt2kk" 
... skipping 292 lines ...
I0712 16:24:52.391737   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.393691   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.395464   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.398422   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.400839   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.402848   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
E0712 16:24:52.404175   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-htvw2\" not found" "controller"="machine" "name"="test-mhc-machine-htvw2" "namespace"="test-mhc-gt2kk"
I0712 16:24:52.405090   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.407002   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.408843   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.410935   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.412723   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:52.414540   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
... skipping 486 lines ...
I0712 16:24:53.407526   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.412229   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.413442   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.414096   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.415216   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.417204   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.422609   10745 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-9dn8b" "target"="test-mhc-5f4zc/test-mhc-bdmfv/test-mhc-machine-9dn8b/"
node created: test-mhc-node-xm5mx
E0712 16:24:53.455513   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xm5mx, got []"  "node"="test-mhc-node-xm5mx"
E0712 16:24:53.455530   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xm5mx, got []"  "node"="test-mhc-node-xm5mx"
E0712 16:24:53.455735   10745 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xm5mx, got []"  "node"="test-mhc-node-xm5mx"
I0712 16:24:53.456631   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.467199   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.490455   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.500791   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.505111   10745 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-9dn8b" "target"="test-mhc-5f4zc/test-mhc-bdmfv/test-mhc-machine-9dn8b/test-mhc-node-xm5mx"
I0712 16:24:53.540182   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.546765   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.568914   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.575399   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
Cleaning up nodes, machines and infra machines.
I0712 16:24:53.581608   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.583692   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
I0712 16:24:53.589060   10745 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-9dn8b" "target"="test-mhc-5f4zc/test-mhc-bdmfv/test-mhc-machine-9dn8b/"
I0712 16:24:53.606143   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nw8p2" "namespace"="test-mhc-5f4zc" "descendants"="Worker machines: test-mhc-machine-9dn8b" "indirect descendants count"=1
I0712 16:24:53.627066   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-nw8p2" "namespace"="test-mhc-5f4zc" "descendants"="Worker machines: test-mhc-machine-9dn8b" "indirect descendants count"=1
E0712 16:24:53.634508   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-bdmfv\" not found" "controller"="machinehealthcheck" "name"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc"
--- PASS: TestMachineHealthCheck_Reconcile (40.96s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.16s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.06s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.04s)
    --- 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 (2.48s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.06s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0712 16:24:53.636395   10745 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:24:53.637641   10745 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:24:53.638951   10745 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:24:53.639352   10745 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:24:53.639819   10745 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:24:53.643376   10745 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0712 16:24:53.643865   10745 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0712 16:24:53.645198   10745 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:24:53.652720   10745 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:24:53.656382   10745 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 57 lines ...
=== RUN   TestGinkgoSuite
Running Suite: Controllers Suite
================================
Random Seed: 1626107031
Will run 16 of 16 specs

•E0712 16:24:53.797051   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-sqzpk\" not found" "controller"="cluster" "name"="test1-sqzpk" "namespace"="default"
I0712 16:24:53.842674   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-nw8p2" "machine"="test-mhc-machine-9dn8b" "namespace"="test-mhc-5f4zc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xm5mx"}
E0712 16:24:53.890460   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9dn8b\" not found" "controller"="machine" "name"="test-mhc-machine-9dn8b" "namespace"="test-mhc-5f4zc"
I0712 16:24:54.634799   10745 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-bdmfv" "namespace"="test-mhc-5f4zc" 
E0712 16:24:54.821708   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-npxz6/test-cluster-zgnzw"
I0712 16:24:54.961927   10745 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-k2wr4" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0712 16:24:55.083113   10745 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-k2wr4" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:24:55.089496   10745 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-k2wr4" "namespace"="default"
E0712 16:24:56.105546   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
•E0712 16:24:57.119397   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-4b8lt\" not found" "controller"="cluster" "name"="test3-4b8lt" "namespace"="default"
E0712 16:24:58.120261   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
E0712 16:24:59.143677   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-gt2kk/test-cluster-dkflj"
E0712 16:24:59.143829   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
•E0712 16:25:00.154179   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5f4zc/test-cluster-nw8p2"
E0712 16:25:00.157716   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2xs7z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2xs7z" "namespace"="default"
E0712 16:25:00.573432   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-v4znj\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-v4znj" "namespace"="test-mhc-b2w7t"
E0712 16:25:01.158345   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
E0712 16:25:01.586851   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-5nfx2\" for machine \"test-mhc-machine-pktmf\" in namespace \"test-mhc-b2w7t\": Cluster.cluster.x-k8s.io \"test-cluster-5nfx2\" not found" "controller"="machine" "name"="test-mhc-machine-pktmf" "namespace"="test-mhc-b2w7t"
E0712 16:25:02.168310   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2xs7z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2xs7z" "namespace"="default"
•E0712 16:25:03.169023   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
E0712 16:25:04.169690   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2xs7z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2xs7z" "namespace"="default"
E0712 16:25:05.179169   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
I0712 16:25:05.215349   10745 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-l69ss" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:25:05.225417   10745 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-l69ss" "namespace"="default" 
E0712 16:25:05.242731   10745 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-l69ss" "namespace"="default"
E0712 16:25:06.179926   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2xs7z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2xs7z" "namespace"="default"
I0712 16:25:06.264997   10745 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-l69ss" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:25:06.265241   10745 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-l69ss" "namespace"="default" "noderef"="id-node-1"
E0712 16:25:06.286995   10745 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-l69ss" "namespace"="default"
E0712 16:25:07.184656   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
•I0712 16:25:07.272779   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-jtsfc" "namespace"="ms-test" "creating"=2 "need"=2
I0712 16:25:07.272826   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-jtsfc" "namespace"="ms-test" 
I0712 16:25:07.285959   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-jtsfc-9g9hb\"" "machineset"="ms-jtsfc" "namespace"="ms-test" 
I0712 16:25:07.286024   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-jtsfc" "namespace"="ms-test" 
I0712 16:25:07.287451   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-pcpfw" "machine"="test6-l69ss" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"cf0966fd-673a-4450-a77b-448f3782b366","apiVersion":"v1"}
I0712 16:25:07.300315   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-jtsfc-hjwb6\"" "machineset"="ms-jtsfc" "namespace"="ms-test" 
E0712 16:25:07.303876   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-l69ss\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-l69ss" "namespace"="default"
I0712 16:25:07.415745   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-jtsfc" "namespace"="ms-test" "creating"=1 "need"=2
I0712 16:25:07.415787   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-jtsfc" "namespace"="ms-test" 
I0712 16:25:07.428727   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-jtsfc-cbq65\"" "machineset"="ms-jtsfc" "namespace"="ms-test" 
E0712 16:25:07.637656   10745 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-jtsfc-cbq65-45292 for machine ms-test/ms-jtsfc-cbq65: the cache is not started, can not read objects" "machineset"="ms-jtsfc" "namespace"="ms-test" 
E0712 16:25:07.760317   10745 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0712 16:25:07.810810   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:25:07.810851   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:07.819194   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-6gzm9-6657c7fddb-kwg7m\"" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:07.819250   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:07.830903   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-6gzm9-6657c7fddb-tqpnw\"" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:07.903830   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
... skipping 4 lines ...
I0712 16:25:08.013088   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:25:08.013142   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:08.021562   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gzm9-6657c7fddb-lj948\"" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" 
I0712 16:25:08.120951   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:25:08.120996   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
I0712 16:25:08.130514   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gzm9-cdfc6fd6c-fhxp5\"" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
E0712 16:25:08.185412   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2xs7z: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2xs7z" "namespace"="default"
E0712 16:25:08.251279   10745 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-6gzm9-cdfc6fd6c-fhxp5-9frmf for machine md-test/md-6gzm9-cdfc6fd6c-fhxp5: the cache is not started, can not read objects" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
I0712 16:25:08.282207   10745 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:25:08.282261   10745 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:25:08.286560   10745 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "machine"="md-6gzm9-6657c7fddb-vhskr"
E0712 16:25:08.304297   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-jtsfc-hjwb6\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-jtsfc-hjwb6" "namespace"="ms-test"
I0712 16:25:08.395368   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:25:08.395422   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
I0712 16:25:08.404781   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gzm9-cdfc6fd6c-hszm6\"" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
I0712 16:25:08.490489   10745 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:25:08.490524   10745 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:25:08.494248   10745 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gzm9-6657c7fddb" "namespace"="md-test" "machine"="md-6gzm9-6657c7fddb-58vfl"
... skipping 11 lines ...
I0712 16:25:08.994334   10745 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gzm9-cdfc6fd6c-wdp47"
I0712 16:25:09.011569   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:25:09.011628   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" 
I0712 16:25:09.021866   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gzm9-74d45c49c5-6sw9k\"" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" 
I0712 16:25:09.185866   10745 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-pcpfw" "namespace"="default" "count"=1
I0712 16:25:09.185924   10745 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-pcpfw" "namespace"="default" "descendants"="Control plane machines: test6-l69ss" "indirect descendants count"=0
E0712 16:25:09.198858   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-k2wr4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-k2wr4" "namespace"="default"
I0712 16:25:09.210508   10745 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:25:09.210549   10745 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:25:09.214499   10745 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gzm9-cdfc6fd6c-hszm6"
I0712 16:25:09.229181   10745 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:25:09.229219   10745 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" 
I0712 16:25:09.239715   10745 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-6gzm9-74d45c49c5-htg9b\"" "machineset"="md-6gzm9-74d45c49c5" "namespace"="md-test" 
I0712 16:25:09.304769   10745 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-pcpfw" "machine"="test6-l69ss" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"cf0966fd-673a-4450-a77b-448f3782b366","apiVersion":"v1"}
E0712 16:25:09.305610   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-l69ss\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-l69ss" "namespace"="default"
I0712 16:25:09.371079   10745 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0712 16:25:09.371133   10745 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:25:09.374713   10745 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" "machine"="md-6gzm9-cdfc6fd6c-fhxp5"
•I0712 16:25:09.471248   10745 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:25:09.472327   10745 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:25:09.472392   10745 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"
... skipping 16 lines ...
I0712 16:25:09.483368   10745 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:25:09.484760   10745 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:25:09.485408   10745 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:25:09.485963   10745 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:25:09.485989   10745 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0712 16:25:09.488195   10745 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0712 16:25:09.490936   10745 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" 
•

Ran 16 of 16 Specs in 15.833 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.83s)
PASS
Tearing down test suite
E0712 16:25:09.492680   10745 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:25:09.492729   10745 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-240273653/tls.crt: no such file or directory"  
I0712 16:25:09.492765   10745 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:25:09.492787   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0712 16:25:09.492826   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0712 16:25:09.492848   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0712 16:25:09.492867   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0712 16:25:09.492886   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:25:09.492905   10745 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0712 16:25:09.492950   10745 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0712 16:25:09.492981   10745 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-240273653/tls.crt: no such file or directory"  
E0712 16:25:09.493491   10745 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:44431/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:44431: connect: connection refused" "machineset"="md-6gzm9-cdfc6fd6c" "namespace"="md-test" 
E0712 16:25:09.493560   10745 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to retrieve InfrastructureMachineTemplate external object \"md-test\"/\"md-template\": Get http://127.0.0.1:44431/apis/infrastructure.cluster.x-k8s.io/v1alpha3/namespaces/md-test/infrastructuremachinetemplates/md-template: dial tcp 127.0.0.1:44431: connect: connection refused" "controller"="machineset" "name"="md-6gzm9-cdfc6fd6c" "namespace"="md-test"
E0712 16:25:09.493909   10745 event.go:272] Unable to write event: 'Post http://127.0.0.1:44431/api/v1/namespaces/md-test/events: dial tcp 127.0.0.1:44431: connect: connection refused' (may retry after sleeping)
E0712 16:25:09.524377   10745 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:44431/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1228&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:44431: connect: connection refused
E0712 16:25:09.524584   10745 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:44431/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1228&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:44431: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	78.455s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 265 lines ...
•I0712 16:24:13.324051   11159 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:24:13.347831   11159 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:24:13.548286   11159 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:24:13.548359   11159 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:24:13.548434   11159 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0712 16:24:14.079144   11159 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0712 16:24:16.126769   11159 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-tkbjx/test-cluster"
•E0712 16:24:16.586773   11159 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-cf8w2/test-cluster"
•E0712 16:24:17.131184   11159 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:38623/?timeout=50ms: dial tcp 127.0.0.1:38623: connect: connection refused"  "cluster"="cluster-cache-test-gb6ld/test-cluster"
•I0712 16:24:17.341826   11159 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:24:17.400436   11159 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:40045/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:40045: connect: connection refused


Ran 5 of 5 Specs in 23.751 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (23.75s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	24.003s
?   	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:24:25.867211   11813 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:24:25.867474   11813 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39443
--- PASS: TestClusterToKubeadmControlPlaneOtherControlPlane (0.00s)
I0712 16:24:25.867762   11813 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
=== RUN   TestReconcileUpdateObservedGeneration
--- FAIL: TestReconcileUpdateObservedGeneration (0.28s)
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=0x20 pc=0x1228968]

goroutine 721 [running]:
testing.tRunner.func1(0xc000406f00)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x192d340, 0x2c79c40)
... skipping 9 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.TestReconcileUpdateObservedGeneration(0xc000406f00)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers/controller_test.go:190 +0x582
testing.tRunner(0xc000406f00, 0x1c38060)
	/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	14.490s
I0712 16:24:26.667162   11846 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:24:26.667286   11846 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:24:26.667314   11846 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:24:26.667329   11846 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:24:26.667410   11846 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:24:26.667432   11846 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1626107053
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: 1626107053
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 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:24:30.330701   11846 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:24:38.653804   11846 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:24:47.639819   11846 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:24:58.770070   11846 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:25:15.243273   11846 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:25:28.251862   11846 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:25:45.899371   11846 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:26:06.822761   11846 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:26:37.839368   11846 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:27:22.996494   11846 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 371 lines ...
I0712 16:24:40.379518   12185 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0712 16:24:40.479603   12185 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:24:40.579986   12185 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0712 16:24:40.580065   12185 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0712 16:24:40.579993   12185 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0712 16:24:40.663122   12185 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-hib81r"} 
•E0712 16:24:40.696175   12185 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:24:41.781243   12185 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-nz26og"} 
E0712 16:24:41.835132   12185 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:24:42.900975   12185 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:24:43.927636   12185 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:24:45.091467   12185 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:24:46.122344   12185 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:24:47.137011   12185 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:24:47.137860   12185 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:24:47.137916   12185 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-533818880/tls.crt: no such file or directory"  
I0712 16:24:47.138005   12185 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:24:47.138025   12185 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0712 16:24:47.138061   12185 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 


Ran 5 of 5 Specs in 23.941 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (23.94s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	24.125s
?   	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:24:25.471035   12319 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 92 lines ...
•I0712 16:24:40.077708   12319 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:24:40.127853   12319 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:24:40.140487   12319 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0712 16:24:40.176904   12319 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:24:40.209258   12319 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0712 16:24:40.211966   12319 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:24:40.212120   12319 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0712 16:24:40.212157   12319 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-295227491/tls.crt: no such file or directory"  
I0712 16:24:40.226631   12319 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 14.697 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.70s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	14.954s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 210 lines ...
/home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:39
  Should patch a clusterv1.Cluster
  /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:411
    updating both spec, status, and adding a condition [It]
    /home/prow/go/src/sigs.k8s.io/cluster-api/util/patch/patch_test.go:550

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



Summarizing 1 Failure:

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

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