This job view page is being replaced by Spyglass soon. Check out the new job view.
PRCecileRobertMichon: 🌱 Add v1alpha4 to metadata.yaml
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-06-30 21:43
Elapsed4m41s
Revision055c70360cbc45c0a6caf928666930354bd9e15c
Refs 4871

No Test Failures!


Error lines from build-log.txt

... skipping 775 lines ...
I0630 21:45:33.969903    8449 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0630 21:45:33.970076    8449 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0630 21:45:33.971199    8449 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0630 21:45:33.971544    8449 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0630 21:45:33.971711    8449 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=34609
I0630 21:45:34.499388    8449 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" 
•E0630 21:45:34.509892    8449 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0630 21:45:34.509933    8449 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-446525977/tls.crt: no such file or directory"  
I0630 21:45:34.509975    8449 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 10.833 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (10.83s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	67.452s
=== 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 ...
I0630 21:44:59.977231   10480 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0630 21:44:59.977253   10480 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
I0630 21:44:59.977260   10480 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0630 21:44:59.977285   10480 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machineset" "worker count"=1
I0630 21:44:59.977482   10480 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
=== RUN   TestClusterReconcilePhases
2021/06/30 21:45:00 http: TLS handshake error from 127.0.0.1:42882: 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
I0630 21:45:00.472746   10480 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"
I0630 21:45:00.475730   10480 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
I0630 21:45:00.516794   10480 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
I0630 21:45:00.518415   10480 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"
E0630 21:45:00.518723   10480 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
I0630 21:45:00.519204   10480 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
I0630 21:45:00.826245   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0630 21:45:00.829390   10480 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0630 21:45:00.836637   10480 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0630 21:45:00.836728   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0630 21:45:00.945642   10480 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0630 21:45:00.945721   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0630 21:45:01.047650   10480 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s" "noderef"="node-1"
E0630 21:45:01.066551   10480 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0630 21:45:01.066856   10480 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0630 21:45:01.102143   10480 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-vp4js\" in namespace \"test-machine-watches-xpz8s\", requeuing: requeue in 1s"  
E0630 21:45:01.249330   10480 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-vp4js\" in namespace \"test-machine-watches-xpz8s\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-vp4js\" in namespace \"test-machine-watches-xpz8s\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s"
--- PASS: TestWatches (0.76s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0630 21:45:01.474170   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-ggt4q" "namespace"="test-machine-watches-xpz8s" "count"=1
I0630 21:45:01.474236   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-ggt4q" "namespace"="test-machine-watches-xpz8s" "descendants"="Worker machines: machine-created-vp4js" "indirect descendants count"=0
I0630 21:45:01.493465   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-ggt4q" "namespace"="test-machine-watches-xpz8s" "count"=1
I0630 21:45:01.493524   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-ggt4q" "namespace"="test-machine-watches-xpz8s" "descendants"="Worker machines: machine-created-vp4js" "indirect descendants count"=0
I0630 21:45:02.249904   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-ggt4q" "machine"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"87e58853-6e96-4a3a-aabb-5efe381332d9","apiVersion":"v1"}
E0630 21:45:02.300878   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-vp4js\" not found" "controller"="machine" "name"="machine-created-vp4js" "namespace"="test-machine-watches-xpz8s"
E0630 21:45:03.355437   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-5grfc\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-jmkbm\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-jmkbm: secrets \"machine-reconcile-jmkbm-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-5grfc" "namespace"="default"
I0630 21:45:04.356130   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-jmkbm" "machine"="machine-created-5grfc" "namespace"="default" "cause"="noderef is nil" "node"=null
I0630 21:45:04.404011   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-jmkbm" "machine"="machine-created-5grfc" "namespace"="default" "cause"="noderef is nil" "node"=null
I0630 21:45:04.425915   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-jmkbm" "machine"="machine-created-5grfc" "namespace"="default" "cause"="noderef is nil" "node"=null
E0630 21:45:04.457478   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-5grfc\" not found" "controller"="machine" "name"="machine-created-5grfc" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.19s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.19s)
=== 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 4 lines ...
I0630 21:45:04.469544   10480 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0630 21:45:04.469642   10480 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine2" "namespace"="default" 
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set
I0630 21:45:04.474340   10480 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"
I0630 21:45:04.476288   10480 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
E0630 21:45:04.488713   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-jmkbm\" not found" "controller"="cluster" "name"="machine-reconcile-jmkbm" "namespace"="default"
I0630 21:45:04.489038   10480 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"
I0630 21:45:04.489191   10480 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "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.01s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner (0.01s)
... skipping 121 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0630 21:45:04.643323   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jsbvk" "namespace"="test-mhc-4fcv9" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0630 21:45:04.697315   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0630 21:45:04.698372   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-lnk5c\" not found"  "cluster"="test-mhc-4fcv9/test-cluster-lnk5c"
E0630 21:45:04.702166   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-jsbvk\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-jsbvk\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-jsbvk" "namespace"="test-mhc-4fcv9"
=== 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
I0630 21:45:05.702436   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vx7gn" "namespace"="test-mhc-5jpcp" 
I0630 21:45:05.702565   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-jsbvk" "namespace"="test-mhc-4fcv9" 
I0630 21:45:05.702595   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-2zgp8" "namespace"="test-mhc-x9jzg" 
I0630 21:45:05.702621   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cppdt" "namespace"="test-mhc-244nx" 
I0630 21:45:05.741921   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:05.865436   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cppdt" "namespace"="test-mhc-244nx" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0630 21:45:05.894832   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cppdt" "namespace"="test-mhc-244nx" 
E0630 21:45:05.910650   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-244nx/test-cluster-qfpjc"
E0630 21:45:05.912281   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-qfpjc\" not found" "controller"="cluster" "name"="test-cluster-qfpjc" "namespace"="test-mhc-244nx"
I0630 21:45:05.924967   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-44m48" "namespace"="test-mhc-rt8gw" 
I0630 21:45:05.941579   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:06.062416   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-44m48" "namespace"="test-mhc-rt8gw" 
E0630 21:45:06.131181   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rt8gw/test-cluster-49vv6"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0630 21:45:06.136591   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-44m48" "namespace"="test-mhc-rt8gw" 
I0630 21:45:06.157441   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.202253   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
inframachine created: test-mhc-machine-infra-4xgjx
machine created: test-mhc-machine-8rj2v
I0630 21:45:06.252893   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.253262   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-8rj2v/"
I0630 21:45:06.270533   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.270971   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-8rj2v/"
I0630 21:45:06.281552   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.282040   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-8rj2v/"
node created: test-mhc-node-vrqmp
E0630 21:45:06.340343   10480 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-vrqmp"
E0630 21:45:06.340473   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-vrqmp, got []"  "node"="test-mhc-node-vrqmp"
I0630 21:45:06.351831   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
inframachine created: test-mhc-machine-infra-hdrhb
I0630 21:45:06.367581   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
machine created: test-mhc-machine-k4khc
I0630 21:45:06.374724   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.386684   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
... skipping 20 lines ...
I0630 21:45:06.473280   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.475216   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.478698   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.480984   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.488160   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.491191   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.491770   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.506842   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.507313   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.514191   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.514632   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.520573   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.521235   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.542136   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.542665   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.555399   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.556119   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
I0630 21:45:06.568422   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.569024   10480 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-q9qdq/test-mhc-zg4p6/test-mhc-machine-k4khc/"
node created: test-mhc-node-zz8kk
E0630 21:45:06.575554   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-zz8kk, got []"  "node"="test-mhc-node-zz8kk"
E0630 21:45:06.575823   10480 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-zz8kk"
I0630 21:45:06.584659   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.587635   10480 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq" "noderef"="test-mhc-node-zz8kk"
I0630 21:45:06.607827   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.609618   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:06.627769   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:06.628285   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-q9qdq/test-mhc-zg4p6/test-mhc-machine-8rj2v/"
E0630 21:45:06.661355   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-q9qdq/test-cluster-qr5ps"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0630 21:45:06.753530   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
inframachine created: test-mhc-machine-infra-fb25g
machine created: test-mhc-machine-z5td7
E0630 21:45:06.843513   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-zg4p6\" not found" "controller"="machinehealthcheck" "name"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq"
E0630 21:45:06.927315   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-xpz8s/machine-reconcile-ggt4q"
E0630 21:45:07.754031   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:07.843820   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:07.879635   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:08.012159   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-zg4p6" "namespace"="test-mhc-q9qdq" 
I0630 21:45:08.012241   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.013238   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.015500   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 314 lines ...
I0630 21:45:08.741609   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.743825   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.745635   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.748272   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.750044   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.751776   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:08.759109   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:08.759289   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.762782   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.765006   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.766845   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.768649   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:08.770398   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 425 lines ...
I0630 21:45:09.764062   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.765883   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.768205   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.769553   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.771440   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.773361   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:09.773521   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:09.774628   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.775091   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-z5td7/"
I0630 21:45:09.788796   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.789129   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-z5td7/"
node created: test-mhc-node-cvnqr
E0630 21:45:09.864392   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cvnqr, got []"  "node"="test-mhc-node-cvnqr"
I0630 21:45:09.875170   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
inframachine created: test-mhc-machine-infra-5bqfj
machine created: test-mhc-machine-7znh2
I0630 21:45:09.901646   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.912834   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:09.913914   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 288 lines ...
I0630 21:45:10.754568   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.759705   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.764323   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.767700   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.769850   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.771995   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:10.774519   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:10.774675   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.777336   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.787327   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.789607   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.791759   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:10.793897   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 390 lines ...
I0630 21:45:11.809521   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.810625   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.811794   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.813037   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.817375   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.824766   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:11.824863   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:11.826280   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.827431   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.831309   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.832438   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.833612   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:11.836676   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 379 lines ...
I0630 21:45:12.830672   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.834830   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.837014   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.838262   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.840161   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.841918   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:12.843611   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:12.843935   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.844386   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-7znh2/"
node created: test-mhc-node-69h4p
E0630 21:45:12.849998   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-69h4p, got []"  "node"="test-mhc-node-69h4p"
I0630 21:45:12.855706   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.856271   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-7znh2/"
I0630 21:45:12.857476   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
inframachine created: test-mhc-machine-infra-gz8dp
machine created: test-mhc-machine-kdf47
I0630 21:45:12.873713   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.879805   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:12.881401   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 304 lines ...
I0630 21:45:13.840230   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.842666   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.845668   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.848365   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.853448   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.855612   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:13.855905   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:13.856959   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.858216   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.860044   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.861680   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.863201   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:13.864407   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
... skipping 302 lines ...
I0630 21:45:14.912699   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.914264   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.915802   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.917272   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.918407   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.919944   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
E0630 21:45:14.920713   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:14.923533   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/"
I0630 21:45:14.939749   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:14.940804   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/"
E0630 21:45:14.989685   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-5fpnd, got []"  "node"="test-mhc-node-5fpnd"
node created: test-mhc-node-5fpnd
Cleaning up nodes, machines and infra machines.
I0630 21:45:15.005608   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:15.006328   10480 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-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/test-mhc-node-5fpnd"
I0630 21:45:15.022968   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:15.023475   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/"
Cleaning up nodes, machines and infra machines.
I0630 21:45:15.034287   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:15.034862   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/"
I0630 21:45:15.039369   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:15.039918   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k4xpg/test-mhc-tvmnf/test-mhc-machine-z5td7/"
I0630 21:45:15.062515   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-grhgb" "namespace"="test-mhc-k4xpg" "count"=2
I0630 21:45:15.062594   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-grhgb" "namespace"="test-mhc-k4xpg" "descendants"="Worker machines: test-mhc-machine-z5td7,test-mhc-machine-7znh2,test-mhc-machine-kdf47" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0630 21:45:15.067484   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-grhgb" "namespace"="test-mhc-k4xpg" "count"=2
I0630 21:45:15.067541   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-grhgb" "namespace"="test-mhc-k4xpg" "descendants"="Worker machines: test-mhc-machine-z5td7,test-mhc-machine-7znh2,test-mhc-machine-kdf47" "indirect descendants count"=1
I0630 21:45:15.168533   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-k4xpg/test-mhc-tvmnf/test-mhc-machine-kdf47/"
E0630 21:45:15.172056   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-tvmnf\" not found" "controller"="machinehealthcheck" "name"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg"
inframachine created: test-mhc-machine-infra-zlxz9
machine created: test-mhc-machine-d99vl
I0630 21:45:15.923833   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-grhgb" "machine"="test-mhc-machine-z5td7" "namespace"="test-mhc-k4xpg" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-cvnqr"}
E0630 21:45:15.970582   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-z5td7\" not found" "controller"="machine" "name"="test-mhc-machine-z5td7" "namespace"="test-mhc-k4xpg"
I0630 21:45:16.172315   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tvmnf" "namespace"="test-mhc-k4xpg" 
I0630 21:45:16.172465   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.185342   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:16.203173   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.208826   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.230961   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.271982   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.355108   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.519150   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:16.840133   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:16.971062   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:17.481142   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:17.972785   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-grhgb" "machine"="test-mhc-machine-7znh2" "namespace"="test-mhc-k4xpg" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-69h4p"}
E0630 21:45:18.023762   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-7znh2\" not found" "controller"="machine" "name"="test-mhc-machine-7znh2" "namespace"="test-mhc-k4xpg"
I0630 21:45:18.762232   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:19.024257   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-grhgb" "machine"="test-mhc-machine-kdf47" "namespace"="test-mhc-k4xpg" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-5fpnd"}
E0630 21:45:19.067476   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-kdf47\" not found" "controller"="machine" "name"="test-mhc-machine-kdf47" "namespace"="test-mhc-k4xpg"
E0630 21:45:20.068507   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
E0630 21:45:20.081029   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k4xpg/test-cluster-grhgb"
I0630 21:45:21.077375   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.084221   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:21.084305   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:21.107953   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
node created: test-mhc-node-wlf8b
E0630 21:45:21.133992   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wlf8b, got []"  "node"="test-mhc-node-wlf8b"
I0630 21:45:21.140125   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
inframachine created: test-mhc-machine-infra-jwzhz
machine created: test-mhc-machine-85rlr
I0630 21:45:21.157839   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.170156   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.171273   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.175248   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.223653   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.304882   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.466346   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:21.787711   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:22.084704   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:22.429092   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.097849   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.104146   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.118067   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.124121   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.135916   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:23.140991   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:23.141365   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:23.162244   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-bmqfl, got []"  "node"="test-mhc-node-bmqfl"
node created: test-mhc-node-bmqfl
inframachine created: test-mhc-machine-infra-7q456
I0630 21:45:23.179377   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
machine created: test-mhc-machine-tgnq7
I0630 21:45:23.190298   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.200618   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:23.710399   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:24.141349   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:25.157266   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.171745   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.189783   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.201360   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.208708   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.215915   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:25.221367   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:25.221687   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.245617   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
E0630 21:45:25.299520   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8prxk, got []"  "node"="test-mhc-node-8prxk"
node created: test-mhc-node-8prxk
I0630 21:45:25.307271   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:25.325347   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:25.363044   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lhqtn" "namespace"="test-mhc-qgzx2" "count"=2
... skipping 5 lines ...
machine created: test-mhc-machine-lhvht
I0630 21:45:25.476843   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:25.518011   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:25.534248   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-cmdpp" "namespace"="test-mhc-qgzx2" 
I0630 21:45:25.534321   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:25.534970   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
E0630 21:45:26.221741   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:27.222271   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lhqtn" "machine"="test-mhc-machine-d99vl" "namespace"="test-mhc-qgzx2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wlf8b"}
E0630 21:45:27.260459   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d99vl\" not found" "controller"="machine" "name"="test-mhc-machine-d99vl" "namespace"="test-mhc-qgzx2"
I0630 21:45:28.261079   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lhqtn" "machine"="test-mhc-machine-85rlr" "namespace"="test-mhc-qgzx2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-bmqfl"}
E0630 21:45:28.309819   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-85rlr\" not found" "controller"="machine" "name"="test-mhc-machine-85rlr" "namespace"="test-mhc-qgzx2"
I0630 21:45:29.312374   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lhqtn" "machine"="test-mhc-machine-tgnq7" "namespace"="test-mhc-qgzx2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8prxk"}
E0630 21:45:29.360539   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-tgnq7\" not found" "controller"="machine" "name"="test-mhc-machine-tgnq7" "namespace"="test-mhc-qgzx2"
I0630 21:45:30.368273   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:30.374135   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
E0630 21:45:30.374752   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
E0630 21:45:30.384047   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qgzx2/test-cluster-lhqtn"
node created: test-mhc-node-ljzft
E0630 21:45:30.437320   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ljzft, got []"  "node"="test-mhc-node-ljzft"
I0630 21:45:30.446361   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
inframachine created: test-mhc-machine-infra-b7mfp
I0630 21:45:30.463457   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
machine created: test-mhc-machine-mm9gb
I0630 21:45:30.469997   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:30.482651   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
E0630 21:45:31.376643   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:32.389988   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.398135   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.415356   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.420927   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.432676   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.438655   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
E0630 21:45:32.443445   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
node created: test-mhc-node-h49bw
E0630 21:45:32.475274   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-h49bw, got []"  "node"="test-mhc-node-h49bw"
I0630 21:45:32.482484   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
inframachine created: test-mhc-machine-infra-5pshw
machine created: test-mhc-machine-d4hcb
I0630 21:45:32.496746   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:32.502695   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:33.462023   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
... skipping 10 lines ...
Cleaning up nodes, machines and infra machines.
I0630 21:45:33.624678   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:33.636495   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:33.638752   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mvpq2" "machine"="test-mhc-machine-d4hcb" "namespace"="test-mhc-jngbw" "cause"="noderef is nil" "node"=null
I0630 21:45:33.639526   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:33.640022   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jngbw/test-mhc-4vcws/test-mhc-machine-lhvht/"
I0630 21:45:33.657274   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:33.657997   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jngbw/test-mhc-4vcws/test-mhc-machine-lhvht/"
I0630 21:45:33.658509   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-jngbw/test-mhc-4vcws/test-mhc-machine-mm9gb/"
I0630 21:45:33.692446   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mvpq2" "namespace"="test-mhc-jngbw" "count"=3
I0630 21:45:33.692529   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mvpq2" "namespace"="test-mhc-jngbw" "descendants"="Worker machines: test-mhc-machine-lhvht,test-mhc-machine-mm9gb,test-mhc-machine-d4hcb" "indirect descendants count"=0
E0630 21:45:33.697111   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d4hcb\" not found" "controller"="machine" "name"="test-mhc-machine-d4hcb" "namespace"="test-mhc-jngbw"
I0630 21:45:33.698168   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-mvpq2" "namespace"="test-mhc-jngbw" "count"=2
I0630 21:45:33.698224   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-mvpq2" "namespace"="test-mhc-jngbw" "descendants"="Worker machines: test-mhc-machine-lhvht,test-mhc-machine-mm9gb" "indirect descendants count"=0
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
inframachine created: test-mhc-machine-infra-rrpwt
machine created: test-mhc-machine-g5jvz
E0630 21:45:33.809931   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-4vcws\" not found" "controller"="machinehealthcheck" "name"="test-mhc-4vcws" "namespace"="test-mhc-jngbw"
I0630 21:45:34.698729   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-mvpq2" "machine"="test-mhc-machine-lhvht" "namespace"="test-mhc-jngbw" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ljzft"}
I0630 21:45:34.810235   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
E0630 21:45:34.810820   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lhvht\" not found" "controller"="machine" "name"="test-mhc-machine-lhvht" "namespace"="test-mhc-jngbw"
I0630 21:45:34.833716   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:34.951354   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vcws" "namespace"="test-mhc-jngbw" 
I0630 21:45:34.951456   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:34.953304   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:34.955057   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:34.958450   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
... skipping 417 lines ...
I0630 21:45:35.851181   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.852880   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.854553   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.856290   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.857995   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.860008   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
E0630 21:45:35.861152   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mm9gb\" not found" "controller"="machine" "name"="test-mhc-machine-mm9gb" "namespace"="test-mhc-jngbw"
I0630 21:45:35.861691   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.863357   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.865060   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.866777   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.868537   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:35.870227   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
... skipping 496 lines ...
I0630 21:45:36.868026   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.871200   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.872228   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.873118   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.877016   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.879866   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
E0630 21:45:36.879879   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:36.881697   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.882048   10480 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-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/"
E0630 21:45:36.894632   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jfsf6, got []"  "node"="test-mhc-node-jfsf6"
node created: test-mhc-node-jfsf6
E0630 21:45:36.894881   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-jfsf6, got []"  "node"="test-mhc-node-jfsf6"
I0630 21:45:36.897456   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.897764   10480 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-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/"
I0630 21:45:36.911768   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.931937   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.937488   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.937856   10480 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-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/test-mhc-node-jfsf6"
I0630 21:45:36.959432   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.959838   10480 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-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/test-mhc-node-jfsf6"
Cleaning up nodes, machines and infra machines.
I0630 21:45:36.965901   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.966262   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/"
I0630 21:45:36.984571   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4kklx" "namespace"="test-mhc-hkl99" "descendants"="Worker machines: test-mhc-machine-g5jvz" "indirect descendants count"=1
I0630 21:45:36.984837   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:36.985156   10480 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-hkl99/test-mhc-lh4d9/test-mhc-machine-g5jvz/"
I0630 21:45:36.989340   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-4kklx" "namespace"="test-mhc-hkl99" "descendants"="Worker machines: test-mhc-machine-g5jvz" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0630 21:45:37.005625   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lh4d9" "namespace"="test-mhc-hkl99" 
I0630 21:45:37.128648   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" "creating"=1 "need"=1
I0630 21:45:37.128694   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:37.141407   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-kptmf-gpkw6\"" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:37.219314   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:37.233662   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:37.253913   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
E0630 21:45:37.880329   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:38.254111   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
E0630 21:45:38.712117   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jngbw/test-cluster-mvpq2"
I0630 21:45:38.881016   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-4kklx" "machine"="test-mhc-machine-g5jvz" "namespace"="test-mhc-hkl99" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-jfsf6"}
E0630 21:45:38.927222   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-g5jvz\" not found" "controller"="machine" "name"="test-mhc-machine-g5jvz" "namespace"="test-mhc-hkl99"
I0630 21:45:39.255429   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.943284   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.944084   10480 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.950422   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.951252   10480 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.964754   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
... skipping 4 lines ...
I0630 21:45:39.983115   10480 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.986341   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.986383   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.996827   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:39.996876   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.256471   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.256936   10480 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-f6fbj/test-mhc-qstnc/mhc-ms-kptmf-gpkw6/"
I0630 21:45:40.263872   10480 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.274632   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.275025   10480 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-f6fbj/test-mhc-qstnc/mhc-ms-kptmf-gpkw6/"
I0630 21:45:40.276562   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.276608   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.282542   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.282886   10480 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-f6fbj/test-mhc-qstnc/mhc-ms-kptmf-gpkw6/"
I0630 21:45:40.284597   10480 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.298157   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.298209   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.379191   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-lcbpr" "namespace"="test-mhc-f6fbj" "count"=1
I0630 21:45:40.379252   10480 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-lcbpr" "namespace"="test-mhc-f6fbj" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-kptmf"
I0630 21:45:40.381362   10480 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-kptmf" "namespace"="test-mhc-f6fbj" "machine"="mhc-ms-kptmf-gpkw6"
I0630 21:45:40.387770   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lcbpr" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" "cause"="cluster is being deleted" "node"=null
I0630 21:45:40.388100   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lcbpr" "namespace"="test-mhc-f6fbj" "descendants"="Machine sets: mhc-ms-kptmf;Worker machines: mhc-ms-kptmf-gpkw6" "indirect descendants count"=1
I0630 21:45:40.389262   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.389599   10480 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-f6fbj/test-mhc-qstnc/mhc-ms-kptmf-gpkw6/"
I0630 21:45:40.396597   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-qstnc" "namespace"="test-mhc-f6fbj" 
I0630 21:45:40.398548   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-lcbpr" "namespace"="test-mhc-f6fbj" "descendants"="Worker machines: mhc-ms-kptmf-gpkw6" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0630 21:45:40.447881   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-lcbpr" "machine"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj" "cause"="cluster is being deleted" "node"=null
E0630 21:45:40.493383   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-kptmf-gpkw6\" not found" "controller"="machine" "name"="mhc-ms-kptmf-gpkw6" "namespace"="test-mhc-f6fbj"
I0630 21:45:40.512560   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
inframachine created: test-mhc-machine-infra-mv588
machine created: test-mhc-machine-qmfsd
I0630 21:45:40.532692   10480 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0630 21:45:40.658537   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:40.659319   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
... skipping 387 lines ...
I0630 21:45:41.502841   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.503641   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.505199   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.506783   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.508522   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.509300   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
E0630 21:45:41.538676   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kwnxf, got []"  "node"="test-mhc-node-kwnxf"
E0630 21:45:41.539010   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kwnxf, got []"  "node"="test-mhc-node-kwnxf"
node created: test-mhc-node-kwnxf
E0630 21:45:41.539631   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-kwnxf, got []"  "node"="test-mhc-node-kwnxf"
I0630 21:45:41.543514   10480 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-qmfsd" "namespace"="test-mhc-l29mf" "noderef"="test-mhc-node-kwnxf"
I0630 21:45:41.559520   10480 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-qmfsd" "target"="test-mhc-l29mf/test-mhc-nb4bl/test-mhc-machine-qmfsd/"
I0630 21:45:41.585626   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.611641   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.615063   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.621774   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.626216   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.630404   10480 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-qmfsd" "target"="test-mhc-l29mf/test-mhc-nb4bl/test-mhc-machine-qmfsd/test-mhc-node-kwnxf"
I0630 21:45:41.651591   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:41.688309   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.692539   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.695367   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.698290   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.713964   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
I0630 21:45:41.718153   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l4bjs" "namespace"="test-mhc-l29mf" "count"=1
I0630 21:45:41.718228   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-l4bjs" "namespace"="test-mhc-l29mf" "descendants"="Worker machines: test-mhc-machine-qmfsd" "indirect descendants count"=0
E0630 21:45:41.724226   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-qmfsd\" in namespace \"test-mhc-l29mf\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-qmfsd" "namespace"="test-mhc-l29mf"
I0630 21:45:41.725773   10480 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-l4bjs" "namespace"="test-mhc-l29mf" "count"=1
I0630 21:45:41.725871   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-l4bjs" "namespace"="test-mhc-l29mf" "descendants"="Worker machines: test-mhc-machine-qmfsd" "indirect descendants count"=0
I0630 21:45:41.726522   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nb4bl" "namespace"="test-mhc-l29mf" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0630 21:45:41.765921   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
inframachine created: test-mhc-machine-infra-8xvml
... skipping 43 lines ...
I0630 21:45:41.996088   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:41.997900   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.000056   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.001960   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.003801   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.005635   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:42.006571   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-hkl99/test-cluster-4kklx"
I0630 21:45:42.007517   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.009389   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.011142   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.012929   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.014615   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.016356   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
... skipping 380 lines ...
I0630 21:45:42.759801   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.761705   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.763543   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.765305   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.767078   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.768951   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:42.769705   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-qmfsd\" not found" "controller"="machine" "name"="test-mhc-machine-qmfsd" "namespace"="test-mhc-l29mf"
I0630 21:45:42.770707   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.772493   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.774306   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.776021   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.777798   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:42.779375   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
... skipping 500 lines ...
I0630 21:45:43.783017   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.784880   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.786592   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.788442   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.790268   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.792066   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:43.794051   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
I0630 21:45:43.794163   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.797709   10480 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-4pszz" "target"="test-mhc-wf9k5/test-mhc-lqxkk/test-mhc-machine-4pszz/"
I0630 21:45:43.844196   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:43.896995   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ks4vz, got []"  "node"="test-mhc-node-ks4vz"
E0630 21:45:43.897238   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ks4vz, got []"  "node"="test-mhc-node-ks4vz"
node created: test-mhc-node-ks4vz
E0630 21:45:43.897349   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-ks4vz, got []"  "node"="test-mhc-node-ks4vz"
I0630 21:45:43.904384   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.923842   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.926983   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.930105   10480 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-4pszz" "target"="test-mhc-wf9k5/test-mhc-lqxkk/test-mhc-machine-4pszz/test-mhc-node-ks4vz"
I0630 21:45:43.945416   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.953534   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.970105   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
Cleaning up nodes, machines and infra machines.
I0630 21:45:43.973293   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.981428   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
I0630 21:45:43.985534   10480 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-4pszz" "target"="test-mhc-wf9k5/test-mhc-lqxkk/test-mhc-machine-4pszz/"
I0630 21:45:43.996572   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7cgfk" "namespace"="test-mhc-wf9k5" "descendants"="Worker machines: test-mhc-machine-4pszz" "indirect descendants count"=1
I0630 21:45:44.001469   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-7cgfk" "namespace"="test-mhc-wf9k5" "descendants"="Worker machines: test-mhc-machine-4pszz" "indirect descendants count"=1
I0630 21:45:44.002284   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:44.007845   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-lqxkk\" not found" "controller"="machinehealthcheck" "name"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5"
--- PASS: TestMachineHealthCheck_Reconcile (39.39s)
    --- 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.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.15s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.24s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (1.33s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (2.27s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0630 21:45:44.009179   10480 machinehealthcheck_controller.go:416]  "msg"="expected a Cluster" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace
--- PASS: TestClusterToMachineHealthCheck (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0630 21:45:44.010961   10480 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
E0630 21:45:44.012544   10480 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0630 21:45:44.012792   10480 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
E0630 21:45:44.014570   10480 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
I0630 21:45:44.021696   10480 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0630 21:45:44.022181   10480 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0630 21:45:44.023490   10480 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0630 21:45:44.029890   10480 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
E0630 21:45:44.031312   10480 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 73 lines ...
I0630 21:45:44.305864   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0630 21:45:44.305913   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" 
I0630 21:45:44.319685   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-6657c7fddb-snrbt\"" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" 
I0630 21:45:44.421488   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0630 21:45:44.421540   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
I0630 21:45:44.434846   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-cdfc6fd6c-5bsxt\"" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
E0630 21:45:44.442456   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="Operation cannot be fulfilled on machinedeployments.cluster.x-k8s.io \"md-snlnk\": the object has been modified; please apply your changes to the latest version and try again" "controller"="machinedeployment" "name"="md-snlnk" "namespace"="md-test"
E0630 21:45:44.515573   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.515827   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.515927   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619505   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619563   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619505   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619607   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619765   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.619804   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-5bsxt-jj2gj, got []"  "node"="md-snlnk-cdfc6fd6c-5bsxt-jj2gj"
E0630 21:45:44.658779   10480 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-snlnk-cdfc6fd6c-5bsxt-jj2gj for machine md-test/md-snlnk-cdfc6fd6c-5bsxt: the cache is not started, can not read objects" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
E0630 21:45:44.794507   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
I0630 21:45:45.008191   10480 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-lqxkk" "namespace"="test-mhc-wf9k5" 
E0630 21:45:45.409707   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-f6fbj/test-cluster-lcbpr"
I0630 21:45:45.460377   10480 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0630 21:45:45.460427   10480 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 21:45:45.471414   10480 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "machine"="md-snlnk-6657c7fddb-t5pm7"
I0630 21:45:45.523191   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0630 21:45:45.523234   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
I0630 21:45:45.544410   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-cdfc6fd6c-fm4wk\"" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
E0630 21:45:45.651113   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
E0630 21:45:45.651185   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
E0630 21:45:45.754716   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
E0630 21:45:45.754768   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
E0630 21:45:45.754853   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
E0630 21:45:45.754913   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-fm4wk-bzhk2, got []"  "node"="md-snlnk-cdfc6fd6c-fm4wk-bzhk2"
I0630 21:45:45.792550   10480 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0630 21:45:45.792604   10480 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 21:45:45.794984   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-7cgfk" "machine"="test-mhc-machine-4pszz" "namespace"="test-mhc-wf9k5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-ks4vz"}
I0630 21:45:45.796138   10480 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "machine"="md-snlnk-6657c7fddb-28cff"
E0630 21:45:45.834661   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4pszz\" not found" "controller"="machine" "name"="test-mhc-machine-4pszz" "namespace"="test-mhc-wf9k5"
I0630 21:45:45.905970   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0630 21:45:45.906035   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
I0630 21:45:45.918703   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-cdfc6fd6c-ljfwz\"" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" 
E0630 21:45:46.001396   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
E0630 21:45:46.001570   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
E0630 21:45:46.004900   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
E0630 21:45:46.004955   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
E0630 21:45:46.005118   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
E0630 21:45:46.005158   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-cdfc6fd6c-ljfwz-rp2w2, got []"  "node"="md-snlnk-cdfc6fd6c-ljfwz-rp2w2"
I0630 21:45:46.042284   10480 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0630 21:45:46.042326   10480 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0630 21:45:46.046218   10480 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snlnk-6657c7fddb" "namespace"="md-test" "machine"="md-snlnk-6657c7fddb-snrbt"
I0630 21:45:46.304573   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0630 21:45:46.304610   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
I0630 21:45:46.314162   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-74d45c49c5-n74q6\"" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
E0630 21:45:46.397531   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
E0630 21:45:46.397530   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
E0630 21:45:46.501001   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
E0630 21:45:46.501055   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
E0630 21:45:46.501001   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
E0630 21:45:46.501089   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-n74q6-9m2f7, got []"  "node"="md-snlnk-74d45c49c5-n74q6-9m2f7"
I0630 21:45:46.532294   10480 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0630 21:45:46.532342   10480 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0630 21:45:46.536338   10480 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "machine"="md-snlnk-cdfc6fd6c-fm4wk"
I0630 21:45:46.646135   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0630 21:45:46.646175   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
I0630 21:45:46.655350   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-74d45c49c5-g2fjp\"" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
E0630 21:45:46.728870   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-g2fjp-wctdw, got []"  "node"="md-snlnk-74d45c49c5-g2fjp-wctdw"
E0630 21:45:46.728884   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-g2fjp-wctdw, got []"  "node"="md-snlnk-74d45c49c5-g2fjp-wctdw"
E0630 21:45:46.736182   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-l29mf/test-cluster-l4bjs"
E0630 21:45:46.832570   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-g2fjp-wctdw, got []"  "node"="md-snlnk-74d45c49c5-g2fjp-wctdw"
E0630 21:45:46.832623   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-g2fjp-wctdw, got []"  "node"="md-snlnk-74d45c49c5-g2fjp-wctdw"
I0630 21:45:46.875870   10480 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0630 21:45:46.875930   10480 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0630 21:45:46.881312   10480 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-snlnk-cdfc6fd6c" "namespace"="md-test" "machine"="md-snlnk-cdfc6fd6c-ljfwz"
I0630 21:45:46.892313   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0630 21:45:46.892362   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
I0630 21:45:46.906732   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-snlnk-74d45c49c5-sjqk6\"" "machineset"="md-snlnk-74d45c49c5" "namespace"="md-test" 
I0630 21:45:46.923571   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:46.923626   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:46.941772   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:45:46.941817   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
E0630 21:45:46.978246   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:45:46.980750   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-sjqk6-68g2b, got []"  "node"="md-snlnk-74d45c49c5-sjqk6-68g2b"
E0630 21:45:47.083992   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-sjqk6-68g2b, got []"  "node"="md-snlnk-74d45c49c5-sjqk6-68g2b"
E0630 21:45:47.084038   10480 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-snlnk-74d45c49c5-sjqk6-68g2b, got []"  "node"="md-snlnk-74d45c49c5-sjqk6-68g2b"
I0630 21:45:47.102918   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-snlnk-74d45c49c5,md-snlnk-cdfc6fd6c;Worker machines: md-snlnk-74d45c49c5-g2fjp,md-snlnk-cdfc6fd6c-ljfwz,md-snlnk-74d45c49c5-n74q6,md-snlnk-cdfc6fd6c-5bsxt,md-snlnk-74d45c49c5-sjqk6,md-snlnk-6657c7fddb-9gsln,md-snlnk-6657c7fddb-jt657" "indirect descendants count"=9
•I0630 21:45:47.106093   10480 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"
I0630 21:45:47.107323   10480 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0630 21:45:47.107439   10480 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"
I0630 21:45:47.107337   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-snlnk-74d45c49c5,md-snlnk-cdfc6fd6c;Worker machines: md-snlnk-cdfc6fd6c-5bsxt,md-snlnk-74d45c49c5-sjqk6,md-snlnk-6657c7fddb-9gsln,md-snlnk-6657c7fddb-jt657,md-snlnk-74d45c49c5-g2fjp,md-snlnk-cdfc6fd6c-ljfwz,md-snlnk-74d45c49c5-n74q6" "indirect descendants count"=9
I0630 21:45:47.108366   10480 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
... skipping 15 lines ...
I0630 21:45:47.121454   10480 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"
•I0630 21:45:47.123000   10480 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"
I0630 21:45:47.123696   10480 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"
I0630 21:45:47.124314   10480 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0630 21:45:47.124368   10480 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0630 21:45:47.124889   10480 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0630 21:45:47.126162   10480 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" 
••E0630 21:45:47.248243   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-fcv9z\" not found" "controller"="cluster" "name"="test1-fcv9z" "namespace"="default"
I0630 21:45:47.978718   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-snlnk-cdfc6fd6c-ljfwz" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-snlnk-cdfc6fd6c-ljfwz-rp2w2"}
E0630 21:45:48.028042   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
•I0630 21:45:48.363400   10480 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-bmwxf" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0630 21:45:48.479683   10480 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-bmwxf" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0630 21:45:48.483297   10480 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-bmwxf" "namespace"="default"
E0630 21:45:49.061518   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
E0630 21:45:49.511454   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
•I0630 21:45:50.065864   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:50.065909   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:50.069837   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:45:50.069874   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
E0630 21:45:50.074069   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:45:50.523221   10480 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-wf9k5/test-cluster-7cgfk"
E0630 21:45:50.534741   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-fsknx\" not found" "controller"="cluster" "name"="test3-fsknx" "namespace"="default"
I0630 21:45:51.074699   10480 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-snlnk-cdfc6fd6c-ljfwz" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-snlnk-cdfc6fd6c-ljfwz-rp2w2"}
E0630 21:45:51.100648   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-snlnk-cdfc6fd6c-ljfwz\" not found" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-ljfwz" "namespace"="md-test"
E0630 21:45:51.535496   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
E0630 21:45:52.105750   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
E0630 21:45:52.545832   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
•E0630 21:45:53.128262   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
I0630 21:45:53.546428   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-snlnk-74d45c49c5,md-snlnk-cdfc6fd6c;Worker machines: md-snlnk-6657c7fddb-9gsln,md-snlnk-6657c7fddb-jt657,md-snlnk-74d45c49c5-g2fjp,md-snlnk-74d45c49c5-sjqk6,md-snlnk-74d45c49c5-n74q6,md-snlnk-cdfc6fd6c-5bsxt" "indirect descendants count"=8
E0630 21:45:53.550170   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:45:54.133113   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:45:54.550869   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
I0630 21:45:55.137895   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:55.137938   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:45:55.141694   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:45:55.141731   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
E0630 21:45:55.146239   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
E0630 21:45:55.560010   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
•E0630 21:45:56.155738   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
E0630 21:45:56.560769   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
E0630 21:45:57.156189   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-8rj2v\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-8rj2v" "namespace"="test-mhc-q9qdq"
E0630 21:45:57.561564   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:45:58.161138   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:45:58.570394   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
E0630 21:45:59.161581   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-qr5ps\" for machine \"test-mhc-machine-k4khc\" in namespace \"test-mhc-q9qdq\": Cluster.cluster.x-k8s.io \"test-cluster-qr5ps\" not found" "controller"="machine" "name"="test-mhc-machine-k4khc" "namespace"="test-mhc-q9qdq"
E0630 21:45:59.571156   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:46:00.166222   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
I0630 21:46:00.571793   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-snlnk-cdfc6fd6c,md-snlnk-74d45c49c5;Worker machines: md-snlnk-6657c7fddb-jt657,md-snlnk-74d45c49c5-g2fjp,md-snlnk-74d45c49c5-sjqk6,md-snlnk-74d45c49c5-n74q6,md-snlnk-cdfc6fd6c-5bsxt,md-snlnk-6657c7fddb-9gsln" "indirect descendants count"=8
E0630 21:46:00.572428   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
I0630 21:46:01.170355   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:01.170392   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:01.173806   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:46:01.173840   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
E0630 21:46:01.177802   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
E0630 21:46:01.573078   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:46:02.182571   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:46:02.573845   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
E0630 21:46:03.195344   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
E0630 21:46:03.574561   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:46:04.200434   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
E0630 21:46:04.575281   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
I0630 21:46:05.204396   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:05.204432   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:05.207654   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:46:05.207684   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
E0630 21:46:05.211441   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:46:05.576100   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
I0630 21:46:06.225730   10480 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-cfmvh" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0630 21:46:06.234612   10480 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-cfmvh" "namespace"="default" 
E0630 21:46:06.247467   10480 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-cfmvh" "namespace"="default"
E0630 21:46:06.577409   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:46:07.252614   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-n74q6\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-n74q6" "namespace"="md-test"
I0630 21:46:07.578020   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-snlnk-74d45c49c5,md-snlnk-cdfc6fd6c;Worker machines: md-snlnk-cdfc6fd6c-5bsxt,md-snlnk-6657c7fddb-9gsln,md-snlnk-6657c7fddb-jt657,md-snlnk-74d45c49c5-g2fjp,md-snlnk-74d45c49c5-sjqk6,md-snlnk-74d45c49c5-n74q6" "indirect descendants count"=8
E0630 21:46:07.578519   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
E0630 21:46:08.257478   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-74d45c49c5-g2fjp\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-74d45c49c5-g2fjp" "namespace"="md-test"
E0630 21:46:08.579203   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-bmwxf: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-bmwxf" "namespace"="default"
E0630 21:46:09.262115   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-snlnk-cdfc6fd6c-5bsxt\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-snlnk-cdfc6fd6c-5bsxt" "namespace"="md-test"
E0630 21:46:09.579883   10480 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-tmkll: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-tmkll" "namespace"="default"
I0630 21:46:10.266374   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:10.266432   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-9gsln" "namespace"="md-test" 
I0630 21:46:10.270055   10480 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:46:10.270091   10480 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-snlnk-6657c7fddb-jt657" "namespace"="md-test" 
I0630 21:46:10.283783   10480 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-cfmvh" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0630 21:46:10.283990   10480 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-cfmvh" "namespace"="default" "noderef"="id-node-1"
E0630 21:46:10.296571   10480 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-cfmvh" "namespace"="default"

------------------------------
• [SLOW TEST:15.061 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 8 lines ...
I0630 21:46:10.789354   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-wvnz7-5s2sp\"" "machineset"="ms-wvnz7" "namespace"="ms-test" 
I0630 21:46:10.789402   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-wvnz7" "namespace"="ms-test" 
I0630 21:46:10.808522   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-wvnz7-hrmzs\"" "machineset"="ms-wvnz7" "namespace"="ms-test" 
I0630 21:46:10.902343   10480 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-wvnz7" "namespace"="ms-test" "creating"=1 "need"=2
I0630 21:46:10.902387   10480 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-wvnz7" "namespace"="ms-test" 
I0630 21:46:10.915028   10480 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-wvnz7-xx44q\"" "machineset"="ms-wvnz7" "namespace"="ms-test" 
E0630 21:46:11.148329   10480 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-wvnz7-xx44q-b85p5 for machine ms-test/ms-wvnz7-xx44q: the cache is not started, can not read objects" "machineset"="ms-wvnz7" "namespace"="ms-test" 
I0630 21:46:11.271207   10480 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-wvnz7-xx44q,ms-wvnz7-hrmzs" "indirect descendants count"=2
•

Ran 16 of 16 Specs in 27.242 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (27.24s)
PASS
Tearing down test suite
I0630 21:46:11.275210   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0630 21:46:11.275255   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0630 21:46:11.275282   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0630 21:46:11.275297   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0630 21:46:11.275306   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0630 21:46:11.275334   10480 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0630 21:46:11.275375   10480 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 21:46:11.275414   10480 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0630 21:46:11.275979   10480 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-115618240/tls.crt: no such file or directory"  
E0630 21:46:11.312010   10480 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:37021/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:37021: connect: connection refused
E0630 21:46:11.312675   10480 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:37021/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:37021: connect: connection refused
E0630 21:46:11.313467   10480 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:37021/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1295&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:37021: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	85.399s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 260 lines ...
I0630 21:44:59.418131   10964 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=42057
I0630 21:44:59.419614   10964 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0630 21:44:59.438459   10964 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}}}
I0630 21:44:59.638940   10964 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0630 21:44:59.639012   10964 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0630 21:44:59.824681   10964 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0630 21:45:01.861271   10964 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-7hnxt/test-cluster"
•E0630 21:45:02.335962   10964 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-md6gx/test-cluster"
•E0630 21:45:02.914384   10964 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:37481/?timeout=50ms: dial tcp 127.0.0.1:37481: connect: connection refused"  "cluster"="cluster-cache-test-nq8jm/test-cluster"
•I0630 21:45:03.036989   10964 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":{}}}
I0630 21:45:03.137402   10964 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0630 21:45:03.137462   10964 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0630 21:45:03.178014   10964 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0630 21:45:03.601730   10964 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0630 21:45:03.601878   10964 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 21:45:03.647601   10964 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:40831/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:40831: connect: connection refused


Ran 5 of 5 Specs in 15.403 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (15.40s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	15.554s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 206 lines ...
I0630 21:45:11.366733   11613 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0630 21:45:11.371259   11613 controller.go:129]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.01s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0630 21:45:11.373750   11613 controller.go:125]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0630 21:45:11.375565   11613 controller.go:135]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0630 21:45:11.375827   11613 controller.go:135]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0630 21:45:31.061873   11613 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I0630 21:45:31.062002   11613 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine  reports APIServerPodHealthy condition is false (Error, )"
=== RUN   TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass
--- PASS: TestPreflightChecks (0.00s)
    --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s)
... skipping 18 lines ...
=== RUN   TestAPIs
Running Suite: Controller Suite
===============================
Random Seed: 1625089498
Will run 1 of 1 specs

E0630 21:45:31.496255   11613 controller.go:125]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-ub70g6\" not found" "kubeadmControlPlane"="kcp-foo-ub70g6" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.431 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.43s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0630 21:45:31.497787   11613 controller.go:244]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-1bwhkh" "kubeadmControlPlane"="kcp-foo-1bwhkh" "namespace"="test" 
I0630 21:45:33.212108   11613 controller.go:329]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-1bwhkh" "kubeadmControlPlane"="kcp-foo-1bwhkh" "namespace"="test" "needRollout"=["kcp-foo-1bwhkh-qdmfw"]
I0630 21:45:33.212260   11613 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-1bwhkh" "kubeadmControlPlane"="kcp-foo-1bwhkh" "namespace"="test" "failures"="[machine kcp-foo-1bwhkh-vb5c8 does not have APIServerPodHealthy condition, machine kcp-foo-1bwhkh-vb5c8 does not have ControllerManagerPodHealthy condition, machine kcp-foo-1bwhkh-vb5c8 does not have SchedulerPodHealthy condition, machine kcp-foo-1bwhkh-vb5c8 does not have EtcdPodHealthy condition, machine kcp-foo-1bwhkh-vb5c8 does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (1.72s)
PASS
I0630 21:45:33.213067   11613 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 21:45:33.213294   11613 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0630 21:45:33.213355   11613 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-657366603/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers	34.786s
I0630 21:45:10.841865   11539 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"
I0630 21:45:10.841978   11539 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0630 21:45:10.842012   11539 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"
I0630 21:45:10.842042   11539 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0630 21:45:10.842127   11539 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"
... skipping 52 lines ...
==================================
Random Seed: 1625089497
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestControlPlane (0.00s)
=== RUN   TestHasUnhealthyMachine
--- PASS: TestHasUnhealthyMachine (0.00s)
=== RUN   TestNewFailureDomainPicker
=== RUN   TestNewFailureDomainPicker/simple
=== RUN   TestNewFailureDomainPicker/no_machines
... skipping 111 lines ...
=======================================
Random Seed: 1625089497
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
E0630 21:45:14.563402   11539 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"  
E0630 21:45:22.886455   11539 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"  
E0630 21:45:31.872477   11539 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"  
E0630 21:45:43.002728   11539 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"  
E0630 21:45:59.475967   11539 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"  
E0630 21:46:12.484534   11539 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"  
E0630 21:46:30.131896   11539 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"  
E0630 21:46:51.055326   11539 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"  
E0630 21:47:22.071887   11539 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"  
E0630 21:48:07.229065   11539 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 72 lines ...
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
I0630 21:48:07.237486   11539 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0630 21:48:07.237606   11539 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0630 21:48:07.237637   11539 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-807614494/tls.crt: no such file or directory"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	190.300s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
PASS
... skipping 287 lines ...
I0630 21:45:20.161186   11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourcesetbinding" 
I0630 21:45:20.260513   11862 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0630 21:45:20.361063   11862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0630 21:45:20.361135   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0630 21:45:20.363069   11862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0630 21:45:20.436847   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-k8shi8"} 
E0630 21:45:20.460301   11862 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"
•I0630 21:45:21.502828   11862 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-9lxqa8"} 
E0630 21:45:21.546137   11862 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"
•E0630 21:45:22.598192   11862 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"
E0630 21:45:23.617923   11862 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"
•E0630 21:45:24.741667   11862 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"
•E0630 21:45:25.763326   11862 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"
E0630 21:45:26.776830   11862 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"
•I0630 21:45:26.782486   11862 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0630 21:45:26.782550   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0630 21:45:26.782599   11862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 


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


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

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



Summarizing 1 Failure:

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

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