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:50
Elapsed4m34s
Revision90135212c719ccceb2be71c351e2ffc1e0d42d3a
Refs 4920

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0712 16:52:57.508431    8464 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0712 16:52:57.508675    8464 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0712 16:52:57.509694    8464 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:52:57.510073    8464 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=43315
I0712 16:52:57.510378    8464 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:52:58.131942    8464 kubeadmconfig_controller.go:223]  "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" 
•E0712 16:52:58.142486    8464 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:52:58.142561    8464 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-023083360/tls.crt: no such file or directory"  
E0712 16:52:58.142584    8464 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:52:58.142603    8464 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-023083360/tls.crt: no such file or directory"  
I0712 16:52:58.142674    8464 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 14.140 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.14s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	72.845s
=== 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 1399 lines ...
I0712 16:52:26.871881   10504 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0712 16:52:26.871915   10504 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0712 16:52:26.871810   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0712 16:52:26.871955   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0712 16:52:26.872083   10504 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
=== RUN   TestClusterReconcilePhases
2021/07/12 16:52:27 http: TLS handshake error from 127.0.0.1:57526: EOF
=== 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:52:27.267746   10504 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:52:27.286586   10504 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infra_config_is_marked_for_deletion
... skipping 104 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:52:27.312560   10504 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:52:27.314185   10504 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:52:27.314536   10504 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:52:27.315030   10504 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:52:27.707126   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0712 16:52:27.807685   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:52:27.816694   10504 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0712 16:52:27.816788   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0712 16:52:27.931632   10504 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0712 16:52:27.931721   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0712 16:52:28.037769   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d" "noderef"="node-1"
E0712 16:52:28.053122   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:52:28.053186   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:52:28.089629   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d" "noderef"="node-1"
E0712 16:52:28.120273   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-b2szp\" in namespace \"test-machine-watches-zrc8d\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d"
E0712 16:52:29.129508   10504 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-b2szp\" in namespace \"test-machine-watches-zrc8d\", requeuing: requeue in 1s"  
E0712 16:52:29.143086   10504 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-b2szp\" in namespace \"test-machine-watches-zrc8d\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-b2szp\" in namespace \"test-machine-watches-zrc8d\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d"
--- PASS: TestWatches (1.86s)
=== 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:52:29.469800   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xbpnx" "namespace"="test-machine-watches-zrc8d" "count"=1
I0712 16:52:29.469869   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xbpnx" "namespace"="test-machine-watches-zrc8d" "descendants"="Worker machines: machine-created-b2szp" "indirect descendants count"=0
I0712 16:52:29.486240   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-xbpnx" "namespace"="test-machine-watches-zrc8d" "count"=1
I0712 16:52:29.486305   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-xbpnx" "namespace"="test-machine-watches-zrc8d" "descendants"="Worker machines: machine-created-b2szp" "indirect descendants count"=0
I0712 16:52:30.143659   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-xbpnx" "machine"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"bc51ae90-7585-4ae4-8c61-fcdee81f3044","apiVersion":"v1"}
E0712 16:52:30.213930   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-b2szp\" not found" "controller"="machine" "name"="machine-created-b2szp" "namespace"="test-machine-watches-zrc8d"
E0712 16:52:31.274917   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-5hfdm\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-m8nfh\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-m8nfh: secrets \"machine-reconcile-m8nfh-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-5hfdm" "namespace"="default"
I0712 16:52:32.275485   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m8nfh" "machine"="machine-created-5hfdm" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:52:32.307961   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m8nfh" "machine"="machine-created-5hfdm" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:52:32.329004   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-m8nfh" "machine"="machine-created-5hfdm" "namespace"="default" "cause"="noderef is nil" "node"=null
E0712 16:52:32.369513   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5hfdm\" not found" "controller"="machine" "name"="machine-created-5hfdm" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.20s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.20s)
=== RUN   TestMachineFinalizer
=== RUN   TestMachineFinalizer/should_add_a_machine_finalizer_to_the_machine_if_it_doesn't_have_one
=== RUN   TestMachineFinalizer/should_append_the_machine_finalizer_to_the_machine_if_it_already_has_a_finalizer
--- PASS: TestMachineFinalizer (0.00s)
... skipping 6 lines ...
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0712 16:52:32.381948   10504 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:52:32.382178   10504 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:52:32.387449   10504 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:52:32.388211   10504 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
E0712 16:52:32.389747   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-m8nfh\" not found" "controller"="cluster" "name"="machine-reconcile-m8nfh" "namespace"="default"
--- PASS: TestMachineOwnerReference (0.02s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.00s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
=== RUN   TestReconcileRequest
=== RUN   TestReconcileRequest/machine_should_be_created
... skipping 118 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/all_machines_are_running (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0712 16:52:32.527885   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gcw64" "namespace"="test-mhc-b2846" 
I0712 16:52:32.557442   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:52:32.558432   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-8hf6v\" not found"  "cluster"="test-mhc-b2846/test-cluster-8hf6v"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
E0712 16:52:32.568837   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-gcw64\" not found" "controller"="machinehealthcheck" "name"="test-mhc-gcw64" "namespace"="test-mhc-b2846"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0712 16:52:33.569189   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-gcw64" "namespace"="test-mhc-b2846" 
I0712 16:52:33.569301   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4c8j5" "namespace"="test-mhc-wplx2" 
I0712 16:52:33.569342   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hd29g" "namespace"="test-mhc-cnxz6" 
I0712 16:52:33.569375   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pwqwt" "namespace"="test-mhc-kscwt" 
I0712 16:52:33.595454   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:33.713948   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pwqwt" "namespace"="test-mhc-kscwt" 
I0712 16:52:33.721770   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pwqwt" "namespace"="test-mhc-kscwt" 
I0712 16:52:33.773142   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-pwqwt" "namespace"="test-mhc-kscwt" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0712 16:52:33.779221   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-kscwt/test-cluster-772tq"
E0712 16:52:33.784600   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-772tq\" not found" "controller"="cluster" "name"="test-cluster-772tq" "namespace"="test-mhc-kscwt"
I0712 16:52:33.795113   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpkv9" "namespace"="test-mhc-s72nf" 
I0712 16:52:33.816811   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:33.939849   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpkv9" "namespace"="test-mhc-s72nf" 
E0712 16:52:34.001004   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-s72nf/test-cluster-lzf55"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0712 16:52:34.006977   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cpkv9" "namespace"="test-mhc-s72nf" 
I0712 16:52:34.125044   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
inframachine created: test-mhc-machine-infra-6p2tm
I0712 16:52:34.149139   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-ltc6v
I0712 16:52:34.184822   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.190435   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.190791   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.201797   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.202098   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.211298   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.211808   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.220606   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.221160   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.238189   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.238612   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.249067   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.249456   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.256225   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.256608   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
node created: test-mhc-node-558v4
E0712 16:52:34.263614   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-558v4"
E0712 16:52:34.263725   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-558v4, got []"  "node"="test-mhc-node-558v4"
I0712 16:52:34.267883   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-ltc6v" "namespace"="test-mhc-82lx9" "noderef"="test-mhc-node-558v4"
I0712 16:52:34.272710   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
inframachine created: test-mhc-machine-infra-vmsdn
I0712 16:52:34.289760   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
machine created: test-mhc-machine-9b6gt
I0712 16:52:34.291314   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
... skipping 52 lines ...
I0712 16:52:34.450193   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.453733   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.455355   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.458480   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.460006   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.468500   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.469087   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-9b6gt/"
I0712 16:52:34.490471   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.490948   10504 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-82lx9/test-mhc-4zmpf/test-mhc-machine-9b6gt/"
E0712 16:52:34.495590   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2cdd7, got []"  "node"="test-mhc-node-2cdd7"
E0712 16:52:34.495805   10504 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-2cdd7"
node created: test-mhc-node-2cdd7
I0712 16:52:34.503566   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.522011   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.524663   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9" "noderef"="test-mhc-node-2cdd7"
Cleaning up nodes, machines and infra machines.
I0712 16:52:34.531621   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.541474   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.545196   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.545820   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.579010   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-k4rmm" "machine"="test-mhc-machine-ltc6v" "namespace"="test-mhc-82lx9" "cause"="no control plane members" "node"={"kind":"Node","name":"test-mhc-node-558v4","uid":"49441291-4be3-4407-8237-583ca0f36d18","apiVersion":"v1"}
I0712 16:52:34.588780   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:34.589296   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-82lx9/test-mhc-4zmpf/test-mhc-machine-ltc6v/"
I0712 16:52:34.589670   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-82lx9/test-mhc-4zmpf/test-mhc-machine-9b6gt/"
E0712 16:52:34.617987   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-82lx9/test-cluster-k4rmm"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0712 16:52:34.651167   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4zmpf\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9"
inframachine created: test-mhc-machine-infra-75xg7
machine created: test-mhc-machine-dv8qv
E0712 16:52:34.706426   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ltc6v\" not found" "controller"="machine" "name"="test-mhc-machine-ltc6v" "namespace"="test-mhc-82lx9"
E0712 16:52:34.804802   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-zrc8d/machine-reconcile-xbpnx"
I0712 16:52:35.651463   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4zmpf" "namespace"="test-mhc-82lx9" 
I0712 16:52:35.651565   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.688334   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:52:35.706816   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:35.806753   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.807589   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.808151   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.809848   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.811595   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:35.813312   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
... skipping 458 lines ...
I0712 16:52:36.712832   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.714898   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.716678   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.717249   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.718370   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.720297   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.721885   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-dv8qv/"
E0712 16:52:36.731637   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:36.754880   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.755219   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-dv8qv/"
node created: test-mhc-node-wj494
E0712 16:52:36.807346   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wj494, got []"  "node"="test-mhc-node-wj494"
I0712 16:52:36.814996   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
inframachine created: test-mhc-machine-infra-sjwx4
I0712 16:52:36.844387   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.854882   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:36.866466   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
machine created: test-mhc-machine-mwmcv
... skipping 372 lines ...
I0712 16:52:37.760054   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.761373   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.762516   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.769722   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.771002   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.772156   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
E0712 16:52:37.774062   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:37.778034   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.779863   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.805976   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.807135   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.809941   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:37.812128   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
... skipping 292 lines ...
I0712 16:52:38.750925   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.753240   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.755595   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.757871   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.760149   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.783935   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.796742   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-mwmcv/"
E0712 16:52:38.799857   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:38.833155   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.833585   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-mwmcv/"
E0712 16:52:38.884988   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wxdjk, got []"  "node"="test-mhc-node-wxdjk"
node created: test-mhc-node-wxdjk
I0712 16:52:38.892691   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
inframachine created: test-mhc-machine-infra-hngh4
I0712 16:52:38.922586   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:38.923957   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
machine created: test-mhc-machine-mn2p6
... skipping 208 lines ...
I0712 16:52:39.795776   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.798257   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.801722   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.806977   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.811606   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.828757   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
E0712 16:52:39.846815   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:39.869934   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.871932   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.873431   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.874787   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.876134   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:39.877620   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
... skipping 272 lines ...
I0712 16:52:40.856026   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.858695   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.861269   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.862975   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.865582   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.867071   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.867511   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-mn2p6/"
E0712 16:52:40.877250   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:40.878468   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.879008   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-mn2p6/"
E0712 16:52:40.951926   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w55p2, got []"  "node"="test-mhc-node-w55p2"
node created: test-mhc-node-w55p2
Cleaning up nodes, machines and infra machines.
I0712 16:52:40.959735   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.960336   10504 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-zbhtr/test-mhc-fqzqp/test-mhc-machine-mn2p6/test-mhc-node-w55p2"
I0712 16:52:40.974584   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.975171   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zbhtr/test-mhc-fqzqp/test-mhc-machine-mn2p6/"
Cleaning up nodes, machines and infra machines.
I0712 16:52:40.986118   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:40.986647   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zbhtr/test-mhc-fqzqp/test-mhc-machine-mn2p6/"
I0712 16:52:40.986964   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-zbhtr/test-mhc-fqzqp/test-mhc-machine-dv8qv/"
I0712 16:52:41.012898   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lnlq2" "namespace"="test-mhc-zbhtr" "count"=2
I0712 16:52:41.012987   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lnlq2" "namespace"="test-mhc-zbhtr" "descendants"="Worker machines: test-mhc-machine-mwmcv,test-mhc-machine-mn2p6,test-mhc-machine-dv8qv" "indirect descendants count"=1
I0712 16:52:41.016617   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lnlq2" "namespace"="test-mhc-zbhtr" "count"=2
I0712 16:52:41.016686   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lnlq2" "namespace"="test-mhc-zbhtr" "descendants"="Worker machines: test-mhc-machine-dv8qv,test-mhc-machine-mwmcv,test-mhc-machine-mn2p6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
inframachine created: test-mhc-machine-infra-58x97
machine created: test-mhc-machine-jgwlb
E0712 16:52:41.198074   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-fqzqp\" not found" "controller"="machinehealthcheck" "name"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr"
I0712 16:52:41.877743   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lnlq2" "machine"="test-mhc-machine-mn2p6" "namespace"="test-mhc-zbhtr" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-w55p2"}
E0712 16:52:41.939598   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mn2p6\" not found" "controller"="machine" "name"="test-mhc-machine-mn2p6" "namespace"="test-mhc-zbhtr"
I0712 16:52:42.198395   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.211346   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:42.331958   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fqzqp" "namespace"="test-mhc-zbhtr" 
I0712 16:52:42.332036   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.337113   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.358020   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.398934   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.479981   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.641832   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:42.940155   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lnlq2" "machine"="test-mhc-machine-mwmcv" "namespace"="test-mhc-zbhtr" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wxdjk"}
I0712 16:52:42.962861   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:42.994969   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mwmcv\" not found" "controller"="machine" "name"="test-mhc-machine-mwmcv" "namespace"="test-mhc-zbhtr"
I0712 16:52:43.605226   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:43.999434   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lnlq2" "machine"="test-mhc-machine-dv8qv" "namespace"="test-mhc-zbhtr" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wj494"}
E0712 16:52:44.057531   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-dv8qv\" not found" "controller"="machine" "name"="test-mhc-machine-dv8qv" "namespace"="test-mhc-zbhtr"
I0712 16:52:44.886309   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:45.057953   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
E0712 16:52:46.033362   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-zbhtr/test-cluster-lnlq2"
I0712 16:52:46.065677   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:46.070429   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:46.070768   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:46.084775   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-m6sx7, got []"  "node"="test-mhc-node-m6sx7"
node created: test-mhc-node-m6sx7
I0712 16:52:46.100639   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
inframachine created: test-mhc-machine-infra-srdnt
I0712 16:52:46.124374   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
machine created: test-mhc-machine-v8vjn
I0712 16:52:46.127886   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
... skipping 7 lines ...
I0712 16:52:47.086829   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.092845   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.105425   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.113233   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.128738   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.134633   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:47.135623   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:47.162197   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
node created: test-mhc-node-cthlh
E0712 16:52:47.240768   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cthlh, got []"  "node"="test-mhc-node-cthlh"
I0712 16:52:47.249518   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
inframachine created: test-mhc-machine-infra-t7jfp
machine created: test-mhc-machine-q9kxc
I0712 16:52:47.287434   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.317879   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:47.319447   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
... skipping 4 lines ...
I0712 16:52:48.208095   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.213994   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.223707   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.229038   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.261478   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.283949   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:48.290230   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4fl4p, got []"  "node"="test-mhc-node-4fl4p"
node created: test-mhc-node-4fl4p
I0712 16:52:48.294722   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
Cleaning up nodes, machines and infra machines.
I0712 16:52:48.307031   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
I0712 16:52:48.328672   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qfp8b" "namespace"="test-mhc-4pdld" 
E0712 16:52:48.329712   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-v8vjn\" in namespace \"test-mhc-4pdld\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-v8vjn" "namespace"="test-mhc-4pdld"
Cleaning up nodes, machines and infra machines.
I0712 16:52:48.370888   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-sgcd8" "namespace"="test-mhc-4pdld" "count"=3
I0712 16:52:48.370981   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-sgcd8" "namespace"="test-mhc-4pdld" "descendants"="Worker machines: test-mhc-machine-v8vjn,test-mhc-machine-q9kxc,test-mhc-machine-jgwlb" "indirect descendants count"=0
I0712 16:52:48.382549   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-sgcd8" "namespace"="test-mhc-4pdld" "count"=3
I0712 16:52:48.382612   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-sgcd8" "namespace"="test-mhc-4pdld" "descendants"="Worker machines: test-mhc-machine-jgwlb,test-mhc-machine-v8vjn,test-mhc-machine-q9kxc" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
... skipping 2 lines ...
inframachine created: test-mhc-machine-infra-8sqtp
machine created: test-mhc-machine-vf47f
I0712 16:52:48.551420   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:48.576449   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:48.584699   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:49.330245   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sgcd8" "machine"="test-mhc-machine-q9kxc" "namespace"="test-mhc-4pdld" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-4fl4p"}
E0712 16:52:49.393964   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-q9kxc\" not found" "controller"="machine" "name"="test-mhc-machine-q9kxc" "namespace"="test-mhc-4pdld"
I0712 16:52:50.394552   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sgcd8" "machine"="test-mhc-machine-v8vjn" "namespace"="test-mhc-4pdld" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-cthlh"}
E0712 16:52:50.444778   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-v8vjn\" not found" "controller"="machine" "name"="test-mhc-machine-v8vjn" "namespace"="test-mhc-4pdld"
I0712 16:52:51.445480   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-sgcd8" "machine"="test-mhc-machine-jgwlb" "namespace"="test-mhc-4pdld" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-m6sx7"}
E0712 16:52:51.509084   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jgwlb\" not found" "controller"="machine" "name"="test-mhc-machine-jgwlb" "namespace"="test-mhc-4pdld"
E0712 16:52:52.509490   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
E0712 16:52:53.396676   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4pdld/test-cluster-sgcd8"
I0712 16:52:53.521671   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.526254   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.542424   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.552414   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.560976   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.570348   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
E0712 16:52:53.594279   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gf77q, got []"  "node"="test-mhc-node-gf77q"
node created: test-mhc-node-gf77q
I0712 16:52:53.602390   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
inframachine created: test-mhc-machine-infra-ttb87
machine created: test-mhc-machine-jw4xx
I0712 16:52:53.619554   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.627528   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.631703   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.635145   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.656432   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.666647   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.676334   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.694974   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
E0712 16:52:53.723027   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-4sbm6, got []"  "node"="test-mhc-node-4sbm6"
node created: test-mhc-node-4sbm6
I0712 16:52:53.736274   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
inframachine created: test-mhc-machine-infra-nswn9
machine created: test-mhc-machine-5ft85
I0712 16:52:53.763825   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.773519   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
... skipping 6 lines ...
Cleaning up nodes, machines and infra machines.
I0712 16:52:53.859932   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.861807   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bdnhk" "machine"="test-mhc-machine-5ft85" "namespace"="test-mhc-rgn8b" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I0712 16:52:53.874414   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.879747   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.880824   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rgn8b/test-mhc-ztt5m/test-mhc-machine-vf47f/"
I0712 16:52:53.911278   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:53.912018   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rgn8b/test-mhc-ztt5m/test-mhc-machine-vf47f/"
I0712 16:52:53.912467   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rgn8b/test-mhc-ztt5m/test-mhc-machine-jw4xx/"
I0712 16:52:53.925917   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bdnhk" "namespace"="test-mhc-rgn8b" "count"=3
I0712 16:52:53.926005   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bdnhk" "namespace"="test-mhc-rgn8b" "descendants"="Worker machines: test-mhc-machine-jw4xx,test-mhc-machine-5ft85,test-mhc-machine-vf47f" "indirect descendants count"=0
E0712 16:52:53.928708   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-5ft85\" not found" "controller"="machine" "name"="test-mhc-machine-5ft85" "namespace"="test-mhc-rgn8b"
I0712 16:52:53.930402   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bdnhk" "namespace"="test-mhc-rgn8b" "count"=2
I0712 16:52:53.930457   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bdnhk" "namespace"="test-mhc-rgn8b" "descendants"="Worker machines: test-mhc-machine-vf47f,test-mhc-machine-jw4xx" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
E0712 16:52:53.936697   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-ztt5m\" not found" "controller"="machinehealthcheck" "name"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b"
inframachine created: test-mhc-machine-infra-r55vc
machine created: test-mhc-machine-l2rdv
I0712 16:52:54.929281   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-bdnhk" "machine"="test-mhc-machine-vf47f" "namespace"="test-mhc-rgn8b" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gf77q"}
I0712 16:52:54.942660   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ztt5m" "namespace"="test-mhc-rgn8b" 
I0712 16:52:54.942758   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:54.960732   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:54.990625   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:54.991880   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:54.993642   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.001021   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.003019   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.005002   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.008174   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
E0712 16:52:55.009893   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vf47f\" not found" "controller"="machine" "name"="test-mhc-machine-vf47f" "namespace"="test-mhc-rgn8b"
I0712 16:52:55.009901   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.011692   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.017816   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.021168   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.023454   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:55.025195   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
... skipping 522 lines ...
I0712 16:52:56.055034   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.056941   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.058658   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.060375   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.062096   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.063775   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
E0712 16:52:56.064973   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-jw4xx\" not found" "controller"="machine" "name"="test-mhc-machine-jw4xx" "namespace"="test-mhc-rgn8b"
I0712 16:52:56.065440   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.067126   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.068892   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.070637   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.072349   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:56.074184   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
... skipping 465 lines ...
I0712 16:52:57.070899   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.072176   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.072691   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.074355   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.076069   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.077156   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.077415   10504 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-rpqk2/test-mhc-fltld/test-mhc-machine-l2rdv/"
E0712 16:52:57.077982   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:52:57.087602   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.087895   10504 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-rpqk2/test-mhc-fltld/test-mhc-machine-l2rdv/"
E0712 16:52:57.094952   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5dxsq, got []"  "node"="test-mhc-node-5dxsq"
node created: test-mhc-node-5dxsq
E0712 16:52:57.095146   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5dxsq, got []"  "node"="test-mhc-node-5dxsq"
I0712 16:52:57.103267   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.128053   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.129038   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.135196   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.141124   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.141628   10504 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-rpqk2/test-mhc-fltld/test-mhc-machine-l2rdv/test-mhc-node-5dxsq"
I0712 16:52:57.170609   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.170989   10504 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-rpqk2/test-mhc-fltld/test-mhc-machine-l2rdv/test-mhc-node-5dxsq"
Cleaning up nodes, machines and infra machines.
I0712 16:52:57.184168   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.184529   10504 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rpqk2/test-mhc-fltld/test-mhc-machine-l2rdv/"
I0712 16:52:57.198751   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rg8sv" "namespace"="test-mhc-rpqk2" "descendants"="Worker machines: test-mhc-machine-l2rdv" "indirect descendants count"=1
I0712 16:52:57.203757   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rg8sv" "namespace"="test-mhc-rpqk2" "descendants"="Worker machines: test-mhc-machine-l2rdv" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0712 16:52:57.375962   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-fltld" "namespace"="test-mhc-rpqk2" 
I0712 16:52:57.410858   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" "creating"=1 "need"=1
I0712 16:52:57.410923   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" 
I0712 16:52:57.423130   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-vszgb-b2c4z\"" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" 
I0712 16:52:57.492296   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:52:57.514250   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:52:57.651957   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:52:58.078561   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rg8sv" "machine"="test-mhc-machine-l2rdv" "namespace"="test-mhc-rpqk2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5dxsq"}
E0712 16:52:58.133687   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l2rdv\" not found" "controller"="machine" "name"="test-mhc-machine-l2rdv" "namespace"="test-mhc-rpqk2"
I0712 16:52:58.654636   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
E0712 16:52:58.962778   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rgn8b/test-cluster-bdnhk"
I0712 16:52:59.150264   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.150706   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.159462   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.159672   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.168408   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.168448   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
... skipping 4 lines ...
I0712 16:52:59.196795   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.196949   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:52:59.655669   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:53:00.203107   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:53:00.203161   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.000703   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.001210   10504 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-5gv6n/test-mhc-hx58q/mhc-ms-vszgb-b2c4z/"
I0712 16:53:01.014464   10504 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.020404   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hx58q" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.020762   10504 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-5gv6n/test-mhc-hx58q/mhc-ms-vszgb-b2c4z/"
I0712 16:53:01.028107   10504 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.028168   10504 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" 
I0712 16:53:01.035361   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-jj8vj" "namespace"="test-mhc-5gv6n" "count"=1
I0712 16:53:01.035425   10504 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-jj8vj" "namespace"="test-mhc-5gv6n" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-vszgb"
I0712 16:53:01.037684   10504 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-vszgb" "namespace"="test-mhc-5gv6n" "machine"="mhc-ms-vszgb-b2c4z"
I0712 16:53:01.040949   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jj8vj" "namespace"="test-mhc-5gv6n" "descendants"="Machine sets: mhc-ms-vszgb;Worker machines: mhc-ms-vszgb-b2c4z" "indirect descendants count"=1
... skipping 3 lines ...
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0712 16:53:01.131938   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
inframachine created: test-mhc-machine-infra-blh2k
I0712 16:53:01.146838   10504 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-cmtmp
I0712 16:53:01.241441   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jj8vj" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" "cause"="cluster is being deleted" "node"=null
E0712 16:53:01.264094   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zdndx, got []"  "node"="test-mhc-node-zdndx"
node created: test-mhc-node-zdndx
E0712 16:53:01.264422   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zdndx, got []"  "node"="test-mhc-node-zdndx"
E0712 16:53:01.264422   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zdndx, got []"  "node"="test-mhc-node-zdndx"
I0712 16:53:01.334520   10504 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-cmtmp" "target"="test-mhc-557fs/test-mhc-dr6ff/test-mhc-machine-cmtmp/"
I0712 16:53:01.355825   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jj8vj" "machine"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n" "cause"="cluster is being deleted" "node"=null
I0712 16:53:01.389858   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
E0712 16:53:01.395679   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-vszgb-b2c4z\" not found" "controller"="machine" "name"="mhc-ms-vszgb-b2c4z" "namespace"="test-mhc-5gv6n"
I0712 16:53:01.418902   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
I0712 16:53:01.421647   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
I0712 16:53:01.427211   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
I0712 16:53:01.431190   10504 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-cmtmp" "target"="test-mhc-557fs/test-mhc-dr6ff/test-mhc-machine-cmtmp/test-mhc-node-zdndx"
I0712 16:53:01.459286   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
Cleaning up nodes, machines and infra machines.
I0712 16:53:01.475666   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
I0712 16:53:01.484042   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dr6ff" "namespace"="test-mhc-557fs" 
I0712 16:53:01.489395   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-bst8j" "namespace"="test-mhc-557fs" "count"=1
I0712 16:53:01.489479   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-bst8j" "namespace"="test-mhc-557fs" "descendants"="Worker machines: test-mhc-machine-cmtmp" "indirect descendants count"=0
... skipping 245 lines ...
I0712 16:53:02.205750   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.207520   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.209345   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.211144   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.213279   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.215121   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
E0712 16:53:02.215976   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rpqk2/test-cluster-rg8sv"
I0712 16:53:02.216962   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.218706   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.220476   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.222240   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.223965   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.225686   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
... skipping 104 lines ...
I0712 16:53:02.435217   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.437485   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.439258   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.441035   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.442990   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.444988   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
E0712 16:53:02.446080   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-cmtmp\" not found" "controller"="machine" "name"="test-mhc-machine-cmtmp" "namespace"="test-mhc-557fs"
I0712 16:53:02.446900   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.448702   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.450704   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.452499   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.454386   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:02.456160   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
... skipping 511 lines ...
I0712 16:53:03.495982   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.497934   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.499888   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.501651   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.503455   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.505001   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
E0712 16:53:03.506682   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
I0712 16:53:03.509277   10504 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-j2nlc" "target"="test-mhc-mwxgc/test-mhc-cvmsd/test-mhc-machine-j2nlc/"
I0712 16:53:03.520429   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
node created: test-mhc-node-kghch
E0712 16:53:03.589906   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kghch, got []"  "node"="test-mhc-node-kghch"
E0712 16:53:03.590144   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kghch, got []"  "node"="test-mhc-node-kghch"
E0712 16:53:03.590604   10504 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kghch, got []"  "node"="test-mhc-node-kghch"
I0712 16:53:03.596557   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.664637   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.674362   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.686995   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.691777   10504 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-j2nlc" "target"="test-mhc-mwxgc/test-mhc-cvmsd/test-mhc-machine-j2nlc/test-mhc-node-kghch"
I0712 16:53:03.716290   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.721259   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.740555   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
Cleaning up nodes, machines and infra machines.
I0712 16:53:03.755357   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.757798   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:03.765404   10504 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-j2nlc" "target"="test-mhc-mwxgc/test-mhc-cvmsd/test-mhc-machine-j2nlc/"
I0712 16:53:03.771995   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rk9cd" "namespace"="test-mhc-mwxgc" "descendants"="Worker machines: test-mhc-machine-j2nlc" "indirect descendants count"=1
I0712 16:53:03.776550   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rk9cd" "namespace"="test-mhc-mwxgc" "descendants"="Worker machines: test-mhc-machine-j2nlc" "indirect descendants count"=1
E0712 16:53:03.786984   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-cvmsd\" not found" "controller"="machinehealthcheck" "name"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc"
--- PASS: TestMachineHealthCheck_Reconcile (31.29s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.06s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.13s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.23s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.45s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.28s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0712 16:53:03.789646   10504 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.01s)
    --- 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.01s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0712 16:53:03.797469   10504 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:53:03.799901   10504 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:53:03.805227   10504 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:53:03.806858   10504 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.01s)
    --- 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:53:03.809897   10504 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0712 16:53:03.810510   10504 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0712 16:53:03.818374   10504 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.01s)
=== 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:53:03.847466   10504 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:53:03.849185   10504 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 82 lines ...
I0712 16:53:03.868357   10504 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:53:03.871138   10504 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:53:03.872359   10504 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:53:03.873298   10504 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:53:03.873350   10504 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0712 16:53:03.874037   10504 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0712 16:53:03.876071   10504 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" 
••E0712 16:53:04.007280   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-2q8rz\" not found" "controller"="cluster" "name"="test1-2q8rz" "namespace"="default"
I0712 16:53:04.507264   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rk9cd" "machine"="test-mhc-machine-j2nlc" "namespace"="test-mhc-mwxgc" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-kghch"}
E0712 16:53:04.560011   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-j2nlc\" not found" "controller"="machine" "name"="test-mhc-machine-j2nlc" "namespace"="test-mhc-mwxgc"
I0712 16:53:04.787372   10504 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cvmsd" "namespace"="test-mhc-mwxgc" 
I0712 16:53:05.211093   10504 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5fpc4" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
•I0712 16:53:05.332097   10504 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-5fpc4" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:53:05.336607   10504 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-5fpc4" "namespace"="default"
E0712 16:53:06.354856   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
•E0712 16:53:07.367623   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-5gv6n/test-cluster-jj8vj"
E0712 16:53:07.382127   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-q79jp\" not found" "controller"="cluster" "name"="test3-q79jp" "namespace"="default"
E0712 16:53:08.382861   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
E0712 16:53:09.408664   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-557fs/test-cluster-bst8j"
E0712 16:53:09.409399   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
•E0712 16:53:10.419416   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-mwxgc/test-cluster-rk9cd"
E0712 16:53:10.422321   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
E0712 16:53:11.423160   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
E0712 16:53:12.432906   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
•E0712 16:53:13.433540   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
E0712 16:53:13.747087   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-k4rmm\" for machine \"test-mhc-machine-9b6gt\" in namespace \"test-mhc-82lx9\": Cluster.cluster.x-k8s.io \"test-cluster-k4rmm\" not found" "controller"="machine" "name"="test-mhc-machine-9b6gt" "namespace"="test-mhc-82lx9"
E0712 16:53:14.434202   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
E0712 16:53:15.446813   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
I0712 16:53:15.565688   10504 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-54bkj" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:53:15.576998   10504 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-54bkj" "namespace"="default" 
E0712 16:53:15.592181   10504 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-54bkj" "namespace"="default"
E0712 16:53:16.447567   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
I0712 16:53:16.608419   10504 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-54bkj" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:53:16.608668   10504 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-54bkj" "namespace"="default" "noderef"="id-node-1"
E0712 16:53:16.620188   10504 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-54bkj" "namespace"="default"
E0712 16:53:17.451805   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"

------------------------------
• [SLOW TEST:5.033 seconds]
Cluster Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/controllers/cluster_controller_test.go:45
  Should successfully set Status.ControlPlaneInitialized on the cluster object if controlplane is ready
... skipping 2 lines ...
I0712 16:53:17.610614   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-879x2" "namespace"="ms-test" "creating"=2 "need"=2
I0712 16:53:17.610656   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-879x2" "namespace"="ms-test" 
I0712 16:53:17.620599   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-2dfjs" "machine"="test6-54bkj" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"a821d7be-dec4-4fa6-ba17-f5400eabeb74","apiVersion":"v1"}
I0712 16:53:17.622309   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-879x2-mt6z4\"" "machineset"="ms-879x2" "namespace"="ms-test" 
I0712 16:53:17.622359   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-879x2" "namespace"="ms-test" 
I0712 16:53:17.636203   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-879x2-vwfnf\"" "machineset"="ms-879x2" "namespace"="ms-test" 
E0712 16:53:17.639284   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-54bkj\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-54bkj" "namespace"="default"
I0712 16:53:17.754221   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-879x2" "namespace"="ms-test" "creating"=1 "need"=2
I0712 16:53:17.754264   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-879x2" "namespace"="ms-test" 
I0712 16:53:17.765745   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-879x2-42xs2\"" "machineset"="ms-879x2" "namespace"="ms-test" 
E0712 16:53:17.975278   10504 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-879x2-42xs2-7fkmp for machine ms-test/ms-879x2-42xs2: the cache is not started, can not read objects" "machineset"="ms-879x2" "namespace"="ms-test" 
E0712 16:53:18.201777   10504 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•I0712 16:53:18.251464   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:53:18.251511   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:18.259778   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-72z9b-6657c7fddb-s4vqj\"" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:18.259841   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:18.272345   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-72z9b-6657c7fddb-xpg9s\"" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
E0712 16:53:18.452693   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
I0712 16:53:18.467431   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:53:18.467486   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:18.477859   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-72z9b-6657c7fddb-f7h25\"" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:18.477915   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
E0712 16:53:18.480990   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Operation cannot be fulfilled on machinedeployments.cluster.x-k8s.io \"md-72z9b\": the object has been modified; please apply your changes to the latest version and try again" "controller"="machinedeployment" "name"="md-72z9b" "namespace"="md-test"
I0712 16:53:18.488269   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-72z9b-6657c7fddb-krt55\"" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
E0712 16:53:18.639698   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-879x2-vwfnf\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-879x2-vwfnf" "namespace"="ms-test"
I0712 16:53:19.453341   10504 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test6-2dfjs" "namespace"="default" "count"=1
I0712 16:53:19.453421   10504 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test6-2dfjs" "namespace"="default" "descendants"="Control plane machines: test6-54bkj" "indirect descendants count"=0
E0712 16:53:19.457466   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-5fpc4: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-5fpc4" "namespace"="default"
I0712 16:53:19.495545   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:53:19.495586   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:19.504503   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-6657c7fddb-5twrf\"" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" 
I0712 16:53:19.593783   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:53:19.593820   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" 
I0712 16:53:19.602922   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-cdfc6fd6c-klp5d\"" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" 
I0712 16:53:19.640131   10504 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test6-2dfjs" "machine"="test6-54bkj" "namespace"="default" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"id-node-1","uid":"a821d7be-dec4-4fa6-ba17-f5400eabeb74","apiVersion":"v1"}
E0712 16:53:19.640735   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get /, Kind= \"\" for Machine \"test6-54bkj\" in namespace \"default\": failed to retrieve  external object \"default\"/\"\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="machine" "name"="test6-54bkj" "namespace"="default"
E0712 16:53:19.716344   10504 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-72z9b-cdfc6fd6c-klp5d-985ss for machine md-test/md-72z9b-cdfc6fd6c-klp5d: the cache is not started, can not read objects" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" 
I0712 16:53:19.738794   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:53:19.738839   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:53:19.743615   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "machine"="md-72z9b-6657c7fddb-f7h25"
I0712 16:53:19.851830   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:53:19.851878   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" 
I0712 16:53:19.859842   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-cdfc6fd6c-r87mm\"" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" 
... skipping 6 lines ...
I0712 16:53:20.216099   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0712 16:53:20.216152   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:53:20.219411   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-72z9b-6657c7fddb" "namespace"="md-test" "machine"="md-72z9b-6657c7fddb-5twrf"
I0712 16:53:20.319069   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:53:20.319120   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
I0712 16:53:20.328977   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-74d45c49c5-lr89b\"" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
E0712 16:53:20.466611   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-ngvx8: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-ngvx8" "namespace"="default"
I0712 16:53:20.555648   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:53:20.555687   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:53:20.559124   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "machine"="md-72z9b-cdfc6fd6c-zct96"
E0712 16:53:20.641127   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster\" for machine \"ms-879x2-42xs2\" in namespace \"ms-test\": Cluster.cluster.x-k8s.io \"test-cluster\" not found" "controller"="machine" "name"="ms-879x2-42xs2" "namespace"="ms-test"
I0712 16:53:20.668206   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:53:20.668321   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
I0712 16:53:20.676634   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-74d45c49c5-kls7p\"" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
I0712 16:53:20.879929   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:53:20.879975   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:53:20.884888   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "machine"="md-72z9b-cdfc6fd6c-r87mm"
I0712 16:53:20.898421   10504 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:53:20.898466   10504 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
I0712 16:53:20.906896   10504 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-72z9b-74d45c49c5-zstcs\"" "machineset"="md-72z9b-74d45c49c5" "namespace"="md-test" 
I0712 16:53:21.010166   10504 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0712 16:53:21.010210   10504 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
E0712 16:53:21.011139   10504 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-72z9b\" not found" "controller"="machinedeployment" "name"="md-72z9b" "namespace"="md-test"
I0712 16:53:21.015618   10504 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-72z9b-cdfc6fd6c" "namespace"="md-test" "machine"="md-72z9b-cdfc6fd6c-klp5d"
•

Ran 16 of 16 Specs in 17.165 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.17s)
PASS
Tearing down test suite
I0712 16:53:21.016243   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:53:21.016295   10504 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:53:21.016479   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0712 16:53:21.016499   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0712 16:53:21.016528   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0712 16:53:21.016558   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:53:21.016586   10504 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
E0712 16:53:21.052163   10504 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:35009/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1231&timeout=10s&timeoutSeconds=372&watch=true: dial tcp 127.0.0.1:35009: connect: connection refused
E0712 16:53:21.052210   10504 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:35009/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1231&timeout=10s&timeoutSeconds=504&watch=true: dial tcp 127.0.0.1:35009: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	70.217s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 261 lines ...
I0712 16:52:28.096362   10975 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:52:28.117904   10975 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:52:28.423695   10975 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:52:28.423764   10975 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:52:28.680588   10975 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0712 16:52:29.294081   10975 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
E0712 16:52:31.361864   10975 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-7sv4l/test-cluster"
•E0712 16:52:31.847493   10975 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-hkdg2/test-cluster"
•E0712 16:52:32.383391   10975 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:42569/?timeout=50ms: dial tcp 127.0.0.1:42569: connect: connection refused"  "cluster"="cluster-cache-test-hbg4v/test-cluster"
•I0712 16:52:32.616774   10975 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0712 16:52:32.717215   10975 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0712 16:52:32.717279   10975 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0712 16:52:32.883610   10975 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:52:32.883866   10975 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0712 16:52:32.938747   10975 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:32977/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:32977: connect: connection refused


Ran 5 of 5 Specs in 19.478 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (19.48s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	19.707s
?   	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 ...
--- PASS: TestClusterToKubeadmControlPlaneOtherControlPlane (0.00s)
=== RUN   TestReconcileUpdateObservedGeneration
I0712 16:52:36.850964   11613 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0712 16:52:36.851924   11613 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:52:36.852137   11613 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=37257
I0712 16:52:36.852319   11613 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
--- FAIL: TestReconcileUpdateObservedGeneration (0.56s)
panic: runtime error: invalid memory address or nil pointer dereference [recovered]
	panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0x1721c6a]

goroutine 1253 [running]:
testing.tRunner.func1(0xc000640800)
	/usr/local/go/src/testing/testing.go:874 +0x3a3
panic(0x192d340, 0x2c79c40)
... skipping 3 lines ...
sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.TestReconcileUpdateObservedGeneration(0xc000640800)
	/home/prow/go/src/sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers/controller_test.go:200 +0x9ee
testing.tRunner(0xc000640800, 0x1c38080)
	/usr/local/go/src/testing/testing.go:909 +0xc9
created by testing.(*T).Run
	/usr/local/go/src/testing/testing.go:960 +0x350
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	12.544s
I0712 16:52:35.762388   11532 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:52:35.762530   11532 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:52:35.762565   11532 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:52:35.762580   11532 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:52:35.762656   11532 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:52:35.762681   11532 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1626108743
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1626108743
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:52:40.496395   11532 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:52:48.819486   11532 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:52:57.805453   11532 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:53:08.935752   11532 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:53:25.408992   11532 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:53:38.417536   11532 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:53:56.065080   11532 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:54:16.988584   11532 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:54:48.005083   11532 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:55:33.162280   11532 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:52:45.349072   11852 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0712 16:52:45.449118   11852 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:52:45.550572   11852 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0712 16:52:45.550658   11852 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0712 16:52:45.550859   11852 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0712 16:52:45.627520   11852 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-q8ytds"} 
E0712 16:52:45.653363   11852 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:52:46.739393   11852 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-1dcc6j"} 
•E0712 16:52:46.783988   11852 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:52:47.859184   11852 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:52:48.881401   11852 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:52:49.998630   11852 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:52:51.028408   11852 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:52:52.043707   11852 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:52:52.050928   11852 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0712 16:52:52.051047   11852 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0712 16:52:52.051139   11852 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:52:52.052103   11852 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0712 16:52:52.052185   11852 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-006689775/tls.crt: no such file or directory"  


Ran 5 of 5 Specs in 18.711 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (18.71s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/addons/controllers	18.858s
?   	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:52:41.012646   12138 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 96 lines ...
I0712 16:52:52.416261   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:52:52.442314   12138 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••I0712 16:52:52.451337   12138 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 11.528 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (11.53s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	11.840s
?   	sigs.k8s.io/cluster-api/exp/util	[no test files]
?   	sigs.k8s.io/cluster-api/feature	[no test files]
?   	sigs.k8s.io/cluster-api/hack/boilerplate/test	[no test files]
... skipping 266 lines ...
--- PASS: TestGetFirstReasonAndMessage (0.00s)
=== RUN   TestNewConditionsGroup
--- PASS: TestNewConditionsGroup (0.00s)
=== RUN   TestMergeRespectPriority
=== RUN   TestMergeRespectPriority/aggregate_nil_list_return_nil
=== RUN   TestMergeRespectPriority/aggregate_empty_list_return_nil
=== RUN   TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error
=== RUN   TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning
=== RUN   TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info
=== RUN   TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info
=== RUN   TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown
=== RUN   TestMergeRespectPriority/nil_conditions_are_ignored
--- PASS: TestMergeRespectPriority (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_nil_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/aggregate_empty_list_return_nil (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/error_it_returns_false/error (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/warning_and_no_false/error,_it_returns_false/warning (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_false/info_and_no_false/error_or_false/warning,_it_returns_false/info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_true_and_no_false/*,_it_returns_info (0.00s)
    --- PASS: TestMergeRespectPriority/When_there_is_unknown_and_no_true_or_false/*,_it_returns_unknown (0.00s)
    --- PASS: TestMergeRespectPriority/nil_conditions_are_ignored (0.00s)
=== RUN   TestNewPatch
=== RUN   TestNewPatch/No_changes_return_empty_patch
... skipping 204 lines ...
I0712 16:53:15.695568   15051 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39077
I0712 16:53:15.695608   15051 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0712 16:53:16.628230   15051 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 8.508 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (8.51s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
... skipping 81 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