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

No Test Failures!


Error lines from build-log.txt

... skipping 315 lines ...
go: finding gopkg.in/tomb.v1 v1.0.0-20141024135613-dd632973f1e7
go: finding gopkg.in/yaml.v3 v3.0.0-20200121175148-a6ecf24a6d71
go: finding github.com/BurntSushi/toml v0.3.1
?   	sigs.k8s.io/cluster-api	[no test files]
# sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers [sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers.test]
controlplane/kubeadm/controllers/controller_test.go:182:67: unknown field 'Tracker' in struct literal of type "sigs.k8s.io/cluster-api/controlplane/kubeadm/internal".Management
controlplane/kubeadm/controllers/controller_test.go:186:26: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:187:26: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:190:34: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:196:34: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:199:28: too many arguments in call to r.Reconcile
controlplane/kubeadm/controllers/controller_test.go:199:29: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:204:34: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:211:26: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:214:33: undefined: ctx
controlplane/kubeadm/controllers/controller_test.go:214:33: too many errors
=== RUN   TestFuzzyConversion
=== RUN   TestFuzzyConversion/for_Cluster
=== RUN   TestFuzzyConversion/for_Machine
=== RUN   TestFuzzyConversion/for_MachineSet
=== RUN   TestFuzzyConversion/for_MachineDeployment
... skipping 453 lines ...
I0712 16:09:16.020553    8324 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0712 16:09:16.021126    8324 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0712 16:09:16.022282    8324 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:09:16.022578    8324 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=36815
I0712 16:09:16.022719    8324 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0712 16:09:16.557564    8324 kubeadmconfig_controller.go:223]  "msg"="Cluster infrastructure is not ready, waiting" "kind"="Machine" "kubeadmconfig"={"Namespace":"default","Name":"my-machine-config"} "name"="my-machine" "version"="109" 
•E0712 16:09:16.568970    8324 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:09:16.569030    8324 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-151228641/tls.crt: no such file or directory"  
E0712 16:09:16.569045    8324 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:09:16.569094    8324 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-151228641/tls.crt: no such file or directory"  
I0712 16:09:16.569257    8324 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 1 of 1 Specs in 13.600 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.60s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	66.878s
=== 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.01s)
    --- 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 1388 lines ...
I0712 16:08:46.705471   10648 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0712 16:08:46.705499   10648 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0712 16:08:46.904610   10648 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0712 16:08:46.904715   10648 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}},"status":{"bootstrapReady":false,"infrastructureReady":false}}}
I0712 16:08:46.904768   10648 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machineset" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0712 16:08:46.904806   10648 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machineset" 
2021/07/12 16:08:47 http: TLS handshake error from 127.0.0.1:49746: EOF
=== RUN   TestClusterReconcilePhases
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_no_error_if_infrastructure_ref_is_nil
=== RUN   TestClusterReconcilePhases/reconcile_infrastructure/returns_error_if_unable_to_reconcile_infrastructure_ref
I0712 16:08:47.102042   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test-cluster" "namespace"="test-namespace" "err"="cannot create a metadata client without a rest config"
I0712 16:08:47.105045   10648 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":{}}}
... skipping 115 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0712 16:08:47.149652   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
=== RUN   TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed
I0712 16:08:47.151603   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
E0712 16:08:47.151949   10648 machine_controller_phases.go:246]  "msg"="Machine infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine \"infra-config1\" for Machine \"machine-test\" in namespace \"default\", requeuing: requeue in 1s"  
=== RUN   TestReconcileInfrastructure/infrastructure_ref_is_paused
I0712 16:08:47.152474   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
--- PASS: TestReconcileInfrastructure (0.00s)
    --- PASS: TestReconcileInfrastructure/new_machine,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machine_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestWatches
I0712 16:08:47.397347   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0712 16:08:47.498459   10648 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0712 16:08:47.507992   10648 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0712 16:08:47.508096   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0712 16:08:47.627660   10648 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0712 16:08:47.627766   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0712 16:08:47.738895   10648 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9" "noderef"="node-1"
E0712 16:08:47.747106   10648 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:08:47.747169   10648 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0712 16:08:47.794494   10648 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-m675b\" in namespace \"test-machine-watches-lx9q9\", requeuing: requeue in 1s"  
E0712 16:08:47.807883   10648 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-m675b\" in namespace \"test-machine-watches-lx9q9\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-m675b\" in namespace \"test-machine-watches-lx9q9\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9"
--- PASS: TestWatches (0.68s)
=== RUN   TestIndexMachineByNodeName
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef
=== RUN   TestIndexMachineByNodeName/when_the_machine_has_valid_a_NodeRef
--- PASS: TestIndexMachineByNodeName (0.00s)
    --- PASS: TestIndexMachineByNodeName/when_the_machine_has_no_NodeRef (0.00s)
... skipping 2 lines ...
=== RUN   TestMachine_Reconcile/reconcile_create
I0712 16:08:47.929677   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-d9pp8" "namespace"="test-machine-watches-lx9q9" "count"=1
I0712 16:08:47.929746   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-d9pp8" "namespace"="test-machine-watches-lx9q9" "descendants"="Worker machines: machine-created-m675b" "indirect descendants count"=0
I0712 16:08:47.946399   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-d9pp8" "namespace"="test-machine-watches-lx9q9" "count"=1
I0712 16:08:47.946482   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-d9pp8" "namespace"="test-machine-watches-lx9q9" "descendants"="Worker machines: machine-created-m675b" "indirect descendants count"=0
I0712 16:08:48.808479   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-d9pp8" "machine"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"c5198fa4-7b04-4011-bcd6-d477baf0247c","apiVersion":"v1"}
E0712 16:08:48.873065   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-m675b\" not found" "controller"="machine" "name"="machine-created-m675b" "namespace"="test-machine-watches-lx9q9"
E0712 16:08:49.918915   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-rwdbg\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-729fc\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-729fc: secrets \"machine-reconcile-729fc-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-rwdbg" "namespace"="default"
I0712 16:08:50.919524   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-729fc" "machine"="machine-created-rwdbg" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:08:50.964688   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-729fc" "machine"="machine-created-rwdbg" "namespace"="default" "cause"="noderef is nil" "node"=null
I0712 16:08:51.000301   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-729fc" "machine"="machine-created-rwdbg" "namespace"="default" "cause"="noderef is nil" "node"=null
E0712 16:08:51.040285   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-rwdbg\" not found" "controller"="machine" "name"="machine-created-rwdbg" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.23s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.23s)
=== 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 ...
I0712 16:08:51.068746   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine2" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:08:51.068856   10648 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
I0712 16:08:51.076104   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine3" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:08:51.076213   10648 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
E0712 16:08:51.079159   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-729fc\" not found" "controller"="cluster" "name"="machine-reconcile-729fc" "namespace"="default"
I0712 16:08:51.084091   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine4" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:08:51.084217   10648 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.01s)
    --- 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 120 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/scaling_down (0.00s)
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0712 16:08:51.233149   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vxhw" "namespace"="test-mhc-7wzlg" 
I0712 16:08:51.258330   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:08:51.258858   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-tjhrp\" not found"  "cluster"="test-mhc-7wzlg/test-cluster-tjhrp"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
E0712 16:08:51.364883   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-4vxhw\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-4vxhw\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-4vxhw" "namespace"="test-mhc-7wzlg"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0712 16:08:52.365241   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-46gkn" "namespace"="test-mhc-wdgxf" 
I0712 16:08:52.365372   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vxhw" "namespace"="test-mhc-7wzlg" 
I0712 16:08:52.365406   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-nc5rw" "namespace"="test-mhc-d6ztk" 
I0712 16:08:52.365435   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6x4rh" "namespace"="test-mhc-78x5r" 
I0712 16:08:52.404898   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:08:52.425981   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6x4rh" "namespace"="test-mhc-78x5r" 
I0712 16:08:52.432303   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6x4rh" "namespace"="test-mhc-78x5r" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
I0712 16:08:52.500367   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6x4rh" "namespace"="test-mhc-78x5r" 
E0712 16:08:52.529126   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-78x5r/test-cluster-p29j8"
E0712 16:08:52.531544   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-p29j8\" not found" "controller"="cluster" "name"="test-cluster-p29j8" "namespace"="test-mhc-78x5r"
I0712 16:08:52.532821   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vrp4" "namespace"="test-mhc-jg97v" 
I0712 16:08:52.548527   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:08:52.578366   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vrp4" "namespace"="test-mhc-jg97v" 
I0712 16:08:52.583495   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vrp4" "namespace"="test-mhc-jg97v" 
E0712 16:08:52.640113   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-jg97v/test-cluster-qcf27"
I0712 16:08:52.644995   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4vrp4" "namespace"="test-mhc-jg97v" 
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0712 16:08:52.770633   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
inframachine created: test-mhc-machine-infra-zp6sc
machine created: test-mhc-machine-c9c8g
I0712 16:08:52.796919   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:08:52.898364   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-c9c8g/"
node created: test-mhc-node-wd5lj
E0712 16:08:52.906807   10648 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-wd5lj"
E0712 16:08:52.906889   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wd5lj, got []"  "node"="test-mhc-node-wd5lj"
inframachine created: test-mhc-machine-infra-js8ph
machine created: test-mhc-machine-dkfwv
I0712 16:08:52.938159   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:52.953794   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:52.954913   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:52.962603   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
... skipping 66 lines ...
I0712 16:08:53.134841   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.137016   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.138208   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.140119   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.141789   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.144106   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.144603   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
I0712 16:08:53.159704   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.160154   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
I0712 16:08:53.161112   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.161489   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
I0712 16:08:53.168206   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.168712   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
I0712 16:08:53.178287   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.179588   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
I0712 16:08:53.205374   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.205892   10648 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-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
E0712 16:08:53.240606   10648 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-v46fc"
node created: test-mhc-node-v46fc
E0712 16:08:53.241537   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-v46fc, got []"  "node"="test-mhc-node-v46fc"
I0712 16:08:53.252364   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.307685   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.315876   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
Cleaning up nodes, machines and infra machines.
I0712 16:08:53.323895   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.324449   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgd87/test-mhc-vtpz5/test-mhc-machine-c9c8g/"
I0712 16:08:53.346678   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ljk5f" "machine"="test-mhc-machine-c9c8g" "namespace"="test-mhc-lgd87" "cause"="no control plane members" "node"={"name":"test-mhc-node-wd5lj"}
I0712 16:08:53.349584   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:53.350160   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgd87/test-mhc-vtpz5/test-mhc-machine-c9c8g/"
I0712 16:08:53.350640   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lgd87/test-mhc-vtpz5/test-mhc-machine-dkfwv/"
E0712 16:08:53.381968   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lgd87/test-cluster-ljk5f"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0712 16:08:53.426944   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-c9c8g\" not found" "controller"="machine" "name"="test-mhc-machine-c9c8g" "namespace"="test-mhc-lgd87"
E0712 16:08:53.545704   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-vtpz5\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87"
inframachine created: test-mhc-machine-infra-cqv5k
E0712 16:08:53.565408   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-lx9q9/machine-reconcile-d9pp8"
machine created: test-mhc-machine-4vxb8
E0712 16:08:54.427325   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:08:54.546032   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtpz5" "namespace"="test-mhc-lgd87" 
I0712 16:08:54.546176   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:54.566741   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:08:54.688312   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:54.689324   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:54.691126   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
... skipping 286 lines ...
I0712 16:08:55.431706   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.433561   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.435530   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.437108   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.437676   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.440321   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
E0712 16:08:55.443924   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:08:55.444388   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.444801   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-4vxb8/"
I0712 16:08:55.459103   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.459454   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-4vxb8/"
E0712 16:08:55.540972   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xnglj, got []"  "node"="test-mhc-node-xnglj"
node created: test-mhc-node-xnglj
I0712 16:08:55.549835   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
inframachine created: test-mhc-machine-infra-bkqzg
machine created: test-mhc-machine-b6mjc
I0712 16:08:55.572682   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:55.582496   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
... skipping 339 lines ...
I0712 16:08:56.490230   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.492906   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.496684   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.498979   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.501002   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.503490   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
E0712 16:08:56.504180   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:08:56.512886   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.528299   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.529581   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.532051   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.533309   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:56.536534   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
... skipping 333 lines ...
I0712 16:08:57.513871   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.515146   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.516497   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.518823   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.520751   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.521904   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.522313   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-b6mjc/"
I0712 16:08:57.533614   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.534062   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-b6mjc/"
E0712 16:08:57.537381   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:08:57.538684   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.539103   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-b6mjc/"
E0712 16:08:57.578462   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-97vgd, got []"  "node"="test-mhc-node-97vgd"
node created: test-mhc-node-97vgd
I0712 16:08:57.588597   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
inframachine created: test-mhc-machine-infra-xtbxb
I0712 16:08:57.616174   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:57.624371   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
machine created: test-mhc-machine-8gr8h
... skipping 282 lines ...
I0712 16:08:58.573410   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.575605   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.578589   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.583992   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.586467   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.603878   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
E0712 16:08:58.604144   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:08:58.606905   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.611727   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.625267   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.638548   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.642039   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:58.644365   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
... skipping 237 lines ...
I0712 16:08:59.606744   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.609435   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.612160   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.614456   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.616147   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.626895   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.627735   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-8gr8h/"
E0712 16:08:59.648490   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
node created: test-mhc-node-wbb4j
E0712 16:08:59.651408   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-wbb4j, got []"  "node"="test-mhc-node-wbb4j"
I0712 16:08:59.651892   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.652548   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-8gr8h/"
I0712 16:08:59.660215   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
Cleaning up nodes, machines and infra machines.
I0712 16:08:59.660861   10648 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-rszg5/test-mhc-stgcr/test-mhc-machine-8gr8h/test-mhc-node-wbb4j"
Cleaning up nodes, machines and infra machines.
I0712 16:08:59.696943   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.697562   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rszg5/test-mhc-stgcr/test-mhc-machine-8gr8h/"
I0712 16:08:59.710909   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:08:59.711569   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rszg5/test-mhc-stgcr/test-mhc-machine-4vxb8/"
I0712 16:08:59.741005   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qr278" "namespace"="test-mhc-rszg5" "count"=2
I0712 16:08:59.741099   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qr278" "namespace"="test-mhc-rszg5" "descendants"="Worker machines: test-mhc-machine-4vxb8,test-mhc-machine-b6mjc,test-mhc-machine-8gr8h" "indirect descendants count"=1
I0712 16:08:59.746087   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-qr278" "namespace"="test-mhc-rszg5" "count"=2
I0712 16:08:59.746147   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-qr278" "namespace"="test-mhc-rszg5" "descendants"="Worker machines: test-mhc-machine-4vxb8,test-mhc-machine-b6mjc,test-mhc-machine-8gr8h" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
inframachine created: test-mhc-machine-infra-fgqbn
machine created: test-mhc-machine-8z6zl
I0712 16:08:59.900938   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rszg5/test-mhc-stgcr/test-mhc-machine-b6mjc/"
I0712 16:08:59.921849   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-rszg5/test-mhc-stgcr/test-mhc-machine-8gr8h/"
E0712 16:08:59.925090   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-stgcr\" not found" "controller"="machinehealthcheck" "name"="test-mhc-stgcr" "namespace"="test-mhc-rszg5"
I0712 16:09:00.649160   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qr278" "machine"="test-mhc-machine-8gr8h" "namespace"="test-mhc-rszg5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-wbb4j"}
E0712 16:09:00.706455   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8gr8h\" not found" "controller"="machine" "name"="test-mhc-machine-8gr8h" "namespace"="test-mhc-rszg5"
I0712 16:09:00.925403   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:00.958575   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:09:00.976237   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-stgcr" "namespace"="test-mhc-rszg5" 
I0712 16:09:00.976318   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:00.981385   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.002466   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.043641   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.124766   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.286063   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.607275   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:01.707209   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qr278" "machine"="test-mhc-machine-b6mjc" "namespace"="test-mhc-rszg5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-97vgd"}
E0712 16:09:01.758719   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-b6mjc\" not found" "controller"="machine" "name"="test-mhc-machine-b6mjc" "namespace"="test-mhc-rszg5"
I0712 16:09:02.248450   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:02.760701   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-qr278" "machine"="test-mhc-machine-4vxb8" "namespace"="test-mhc-rszg5" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xnglj"}
E0712 16:09:02.808107   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-4vxb8\" not found" "controller"="machine" "name"="test-mhc-machine-4vxb8" "namespace"="test-mhc-rszg5"
I0712 16:09:03.529554   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
E0712 16:09:03.808507   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
E0712 16:09:04.760864   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-rszg5/test-cluster-qr278"
I0712 16:09:04.817955   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:04.822177   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
E0712 16:09:04.822709   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:09:04.853412   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
node created: test-mhc-node-8rrfq
E0712 16:09:04.865427   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-8rrfq, got []"  "node"="test-mhc-node-8rrfq"
I0712 16:09:04.874006   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
inframachine created: test-mhc-machine-infra-vgzm2
machine created: test-mhc-machine-vmhh8
I0712 16:09:04.896527   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:04.911222   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:04.919009   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
... skipping 4 lines ...
I0712 16:09:05.535737   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.842966   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.853539   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.868440   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.873939   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.888254   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
E0712 16:09:05.899189   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:09:05.899400   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:05.943250   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
E0712 16:09:06.002623   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-h4hv2, got []"  "node"="test-mhc-node-h4hv2"
node created: test-mhc-node-h4hv2
I0712 16:09:06.013598   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
inframachine created: test-mhc-machine-infra-djrfv
I0712 16:09:06.025543   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
machine created: test-mhc-machine-9dm8z
I0712 16:09:06.033198   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
... skipping 6 lines ...
I0712 16:09:06.977185   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:06.982639   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:06.987915   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:06.992025   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:07.021994   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:07.025923   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
E0712 16:09:07.043447   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-w8fj5, got []"  "node"="test-mhc-node-w8fj5"
node created: test-mhc-node-w8fj5
I0712 16:09:07.055148   10648 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-9dm8z" "namespace"="test-mhc-k5f7l" "noderef"="test-mhc-node-w8fj5"
I0712 16:09:07.068775   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
Cleaning up nodes, machines and infra machines.
Cleaning up nodes, machines and infra machines.
I0712 16:09:07.126141   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
... skipping 2 lines ...
I0712 16:09:07.143619   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-ddb9v" "namespace"="test-mhc-k5f7l" "count"=2
I0712 16:09:07.143684   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ddb9v" "namespace"="test-mhc-k5f7l" "descendants"="Worker machines: test-mhc-machine-8z6zl,test-mhc-machine-vmhh8,test-mhc-machine-9dm8z" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_less_than_the_NodeStartupTimeout
inframachine created: test-mhc-machine-infra-wdhkc
machine created: test-mhc-machine-wcmzq
I0712 16:09:07.309622   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ddb9v" "machine"="test-mhc-machine-vmhh8" "namespace"="test-mhc-k5f7l" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-h4hv2"}
E0712 16:09:07.357481   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-vmhh8\" not found" "controller"="machine" "name"="test-mhc-machine-vmhh8" "namespace"="test-mhc-k5f7l"
E0712 16:09:07.505566   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-8gm7w\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-8gm7w\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l"
I0712 16:09:08.358942   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ddb9v" "machine"="test-mhc-machine-8z6zl" "namespace"="test-mhc-k5f7l" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-8rrfq"}
E0712 16:09:08.419412   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8z6zl\" not found" "controller"="machine" "name"="test-mhc-machine-8z6zl" "namespace"="test-mhc-k5f7l"
I0712 16:09:08.505922   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:08.531404   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:09:08.562518   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-8gm7w" "namespace"="test-mhc-k5f7l" 
I0712 16:09:08.562600   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
E0712 16:09:09.435851   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:09:09.435888   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:09.442814   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
node created: test-mhc-node-xjph2
E0712 16:09:09.503802   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xjph2, got []"  "node"="test-mhc-node-xjph2"
E0712 16:09:09.503802   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xjph2, got []"  "node"="test-mhc-node-xjph2"
I0712 16:09:09.512009   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
inframachine created: test-mhc-machine-infra-t5n75
machine created: test-mhc-machine-nd7xd
I0712 16:09:09.535944   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:09.548538   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:10.436462   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ddb9v" "machine"="test-mhc-machine-9dm8z" "namespace"="test-mhc-k5f7l" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"test-mhc-node-w8fj5","uid":"5be34dcd-05b0-4748-bdc9-7d1c0a37ca81","apiVersion":"v1"}
E0712 16:09:10.483700   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-9dm8z\" not found" "controller"="machine" "name"="test-mhc-machine-9dm8z" "namespace"="test-mhc-k5f7l"
I0712 16:09:11.508960   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.510120   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.520670   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.529136   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.536931   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.550803   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.556395   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.569284   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.584720   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.595498   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.610641   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.629734   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
node created: test-mhc-node-cpwcx
E0712 16:09:11.642013   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cpwcx, got []"  "node"="test-mhc-node-cpwcx"
E0712 16:09:11.642065   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-cpwcx, got []"  "node"="test-mhc-node-cpwcx"
I0712 16:09:11.646677   10648 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-nd7xd" "namespace"="test-mhc-z4z4q" "noderef"="test-mhc-node-cpwcx"
I0712 16:09:11.655582   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
inframachine created: test-mhc-machine-infra-vktfj
I0712 16:09:11.676985   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.678615   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.682792   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
... skipping 9 lines ...
Cleaning up nodes, machines and infra machines.
I0712 16:09:11.794958   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.800793   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rxlcc" "machine"="test-mhc-machine-nrqh9" "namespace"="test-mhc-z4z4q" "cause"="noderef is nil" "node"=null
Cleaning up nodes, machines and infra machines.
I0712 16:09:11.807988   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.811713   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.812331   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-wcmzq/"
I0712 16:09:11.833185   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.833853   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-wcmzq/"
I0712 16:09:11.837776   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-nd7xd/"
I0712 16:09:11.881978   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rxlcc" "namespace"="test-mhc-z4z4q" "count"=3
I0712 16:09:11.882079   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rxlcc" "namespace"="test-mhc-z4z4q" "descendants"="Worker machines: test-mhc-machine-nd7xd,test-mhc-machine-nrqh9,test-mhc-machine-wcmzq" "indirect descendants count"=0
I0712 16:09:11.883604   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:11.884258   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-wcmzq/"
I0712 16:09:11.884729   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-nd7xd/"
I0712 16:09:11.895614   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-rxlcc" "namespace"="test-mhc-z4z4q" "count"=3
I0712 16:09:11.895672   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-rxlcc" "namespace"="test-mhc-z4z4q" "descendants"="Worker machines: test-mhc-machine-wcmzq,test-mhc-machine-nd7xd,test-mhc-machine-nrqh9" "indirect descendants count"=0
I0712 16:09:11.896049   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
I0712 16:09:11.896588   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-wcmzq/"
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
I0712 16:09:11.897082   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-z4z4q/test-mhc-6w9wx/test-mhc-machine-nd7xd/"
E0712 16:09:11.897877   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nrqh9\" not found" "controller"="machine" "name"="test-mhc-machine-nrqh9" "namespace"="test-mhc-z4z4q"
E0712 16:09:11.899954   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6w9wx\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q"
inframachine created: test-mhc-machine-infra-l5xpn
machine created: test-mhc-machine-6ncx5
E0712 16:09:12.158415   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-k5f7l/test-cluster-ddb9v"
I0712 16:09:12.898529   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-rxlcc" "machine"="test-mhc-machine-wcmzq" "namespace"="test-mhc-z4z4q" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xjph2"}
I0712 16:09:12.900244   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6w9wx" "namespace"="test-mhc-z4z4q" 
I0712 16:09:12.900336   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:12.932291   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0712 16:09:12.975043   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-wcmzq\" not found" "controller"="machine" "name"="test-mhc-machine-wcmzq" "namespace"="test-mhc-z4z4q"
I0712 16:09:12.981459   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:12.986864   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:12.996433   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:13.011105   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:13.013723   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:13.015740   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
... skipping 473 lines ...
I0712 16:09:14.086373   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.088436   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.090285   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.095127   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.096946   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.098927   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
E0712 16:09:14.099780   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nd7xd\" not found" "controller"="machine" "name"="test-mhc-machine-nd7xd" "namespace"="test-mhc-z4z4q"
I0712 16:09:14.108217   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.111115   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.113982   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.115969   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.117865   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:14.119786   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
... skipping 421 lines ...
I0712 16:09:15.104315   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.106085   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.110129   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.110742   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.111856   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.114735   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.115053   10648 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-g5bgp/test-mhc-4h6mp/test-mhc-machine-6ncx5/"
E0712 16:09:15.116224   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:09:15.126245   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.126549   10648 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-g5bgp/test-mhc-4h6mp/test-mhc-machine-6ncx5/"
E0712 16:09:15.155017   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9jg9w, got []"  "node"="test-mhc-node-9jg9w"
E0712 16:09:15.155258   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9jg9w, got []"  "node"="test-mhc-node-9jg9w"
node created: test-mhc-node-9jg9w
I0712 16:09:15.170934   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.190411   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.196055   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.196395   10648 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-g5bgp/test-mhc-4h6mp/test-mhc-machine-6ncx5/test-mhc-node-9jg9w"
I0712 16:09:15.211984   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.212479   10648 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-g5bgp/test-mhc-4h6mp/test-mhc-machine-6ncx5/test-mhc-node-9jg9w"
Cleaning up nodes, machines and infra machines.
I0712 16:09:15.220004   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.220385   10648 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-g5bgp/test-mhc-4h6mp/test-mhc-machine-6ncx5/"
I0712 16:09:15.236318   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j9gmf" "namespace"="test-mhc-g5bgp" "descendants"="Worker machines: test-mhc-machine-6ncx5" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0712 16:09:15.242588   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-j9gmf" "namespace"="test-mhc-g5bgp" "descendants"="Worker machines: test-mhc-machine-6ncx5" "indirect descendants count"=1
I0712 16:09:15.394950   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-4h6mp" "namespace"="test-mhc-g5bgp" 
I0712 16:09:15.476608   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" "creating"=1 "need"=1
I0712 16:09:15.476667   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:15.493576   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-mdb5c-fhmhc\"" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:15.584445   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:15.618339   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0712 16:09:15.640747   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:15.641518   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:16.116969   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-j9gmf" "machine"="test-mhc-machine-6ncx5" "namespace"="test-mhc-g5bgp" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9jg9w"}
E0712 16:09:16.173072   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-6ncx5\" not found" "controller"="machine" "name"="test-mhc-machine-6ncx5" "namespace"="test-mhc-g5bgp"
I0712 16:09:16.641098   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
E0712 16:09:16.912187   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-z4z4q/test-cluster-rxlcc"
I0712 16:09:17.183425   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.184310   10648 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.189952   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.190564   10648 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.207624   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.207682   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
... skipping 4 lines ...
I0712 16:09:17.236355   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.236403   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:17.642229   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:18.233307   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:18.233362   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.000766   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.001305   10648 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-fpgbx/test-mhc-kwwbq/mhc-ms-mdb5c-fhmhc/"
I0712 16:09:19.009929   10648 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.018010   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.018400   10648 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-fpgbx/test-mhc-kwwbq/mhc-ms-mdb5c-fhmhc/"
I0712 16:09:19.028607   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.028672   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.037242   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.037587   10648 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-fpgbx/test-mhc-kwwbq/mhc-ms-mdb5c-fhmhc/"
I0712 16:09:19.038549   10648 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.056797   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.056855   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.126924   10648 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" "machine"="mhc-ms-mdb5c-fhmhc"
I0712 16:09:19.126924   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-cqntl" "namespace"="test-mhc-fpgbx" "count"=1
I0712 16:09:19.127150   10648 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-cqntl" "namespace"="test-mhc-fpgbx" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-mdb5c"
I0712 16:09:19.132700   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cqntl" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" "cause"="cluster is being deleted" "node"=null
I0712 16:09:19.132831   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.133181   10648 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-fpgbx/test-mhc-kwwbq/mhc-ms-mdb5c-fhmhc/"
I0712 16:09:19.137231   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kwwbq" "namespace"="test-mhc-fpgbx" 
I0712 16:09:19.146527   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cqntl" "namespace"="test-mhc-fpgbx" "descendants"="Machine sets: mhc-ms-mdb5c;Worker machines: mhc-ms-mdb5c-fhmhc" "indirect descendants count"=1
I0712 16:09:19.153863   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-cqntl" "namespace"="test-mhc-fpgbx" "descendants"="Worker machines: mhc-ms-mdb5c-fhmhc" "indirect descendants count"=1
E0712 16:09:19.156440   10648 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-fpgbx\"/\"mhc-ms-template-dtrph\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-dtrph\" not found" "machineset"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx" 
E0712 16:09:19.156663   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to retrieve InfrastructureMachineTemplate external object \"test-mhc-fpgbx\"/\"mhc-ms-template-dtrph\": infrastructuremachinetemplates.infrastructure.cluster.x-k8s.io \"mhc-ms-template-dtrph\" not found" "controller"="machineset" "name"="mhc-ms-mdb5c" "namespace"="test-mhc-fpgbx"
=== RUN   TestMachineHealthCheck_Reconcile/when_a_machine_is_paused
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created
I0712 16:09:19.345404   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-cqntl" "machine"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx" "cause"="cluster is being deleted" "node"=null
E0712 16:09:19.393586   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-mdb5c-fhmhc\" not found" "controller"="machine" "name"="mhc-ms-mdb5c-fhmhc" "namespace"="test-mhc-fpgbx"
I0712 16:09:19.412882   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
inframachine created: test-mhc-machine-infra-txhmp
I0712 16:09:19.432637   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-8scg8
I0712 16:09:19.456659   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:19.481281   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
... skipping 290 lines ...
I0712 16:09:20.246248   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.248188   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.250032   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.251841   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.253732   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.256383   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
E0712 16:09:20.259910   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-g5bgp/test-cluster-j9gmf"
I0712 16:09:20.260223   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.262078   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.264165   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.266220   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.268075   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.269910   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
... skipping 61 lines ...
I0712 16:09:20.399688   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.401618   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.403425   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.404607   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.405259   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:20.406446   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
E0712 16:09:20.407891   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
I0712 16:09:20.408217   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
E0712 16:09:20.450289   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mhp9d, got []"  "node"="test-mhc-node-mhp9d"
node created: test-mhc-node-mhp9d
E0712 16:09:20.450670   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-mhp9d, got []"  "node"="test-mhc-node-mhp9d"
I0712 16:09:20.474999   10648 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-8scg8" "target"="test-mhc-h4zf9/test-mhc-ccdmj/test-mhc-machine-8scg8/"
I0712 16:09:20.494400   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
E0712 16:09:20.515506   10648 machinehealthcheck_controller.go:320] controllers/MachineHealthCheck "msg"="failed to patch healthy machine status for machine" "error"="error patching conditions: The condition \"HealthCheckSucceeded\" was modified by a different process and this caused a merge/AddCondition conflict:   \u0026v1alpha3.Condition{\n  \tType:               \"HealthCheckSucceeded\",\n- \tStatus:             \"False\",\n+ \tStatus:             \"True\",\n- \tSeverity:           \"Warning\",\n+ \tSeverity:           \"\",\n  \tLastTransitionTime: v1.Time{Time: s\"2021-07-12 16:09:20 +0000 UTC\"},\n- \tReason:             \"NodeStartupTimeout\",\n+ \tReason:             \"\",\n- \tMessage:            \"Node failed to report startup in 1ms\",\n+ \tMessage:            \"\",\n  }\n"  "machine"="test-mhc-machine-8scg8"
E0712 16:09:20.515588   10648 machinehealthcheck_controller.go:167] controllers/MachineHealthCheck "msg"="Failed to reconcile MachineHealthCheck" "error"="failed to patch healthy machine status for machine: test-mhc-h4zf9/test-mhc-machine-8scg8: error patching conditions: The condition \"HealthCheckSucceeded\" was modified by a different process and this caused a merge/AddCondition conflict:   \u0026v1alpha3.Condition{\n  \tType:               \"HealthCheckSucceeded\",\n- \tStatus:             \"False\",\n+ \tStatus:             \"True\",\n- \tSeverity:           \"Warning\",\n+ \tSeverity:           \"\",\n  \tLastTransitionTime: v1.Time{Time: s\"2021-07-12 16:09:20 +0000 UTC\"},\n- \tReason:             \"NodeStartupTimeout\",\n+ \tReason:             \"\",\n- \tMessage:            \"Node failed to report startup in 1ms\",\n+ \tMessage:            \"\",\n  }\n" "cluster"="test-cluster-dcpv6" 
E0712 16:09:20.525259   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch healthy machine status for machine: test-mhc-h4zf9/test-mhc-machine-8scg8: error patching conditions: The condition \"HealthCheckSucceeded\" was modified by a different process and this caused a merge/AddCondition conflict:   \u0026v1alpha3.Condition{\n  \tType:               \"HealthCheckSucceeded\",\n- \tStatus:             \"False\",\n+ \tStatus:             \"True\",\n- \tSeverity:           \"Warning\",\n+ \tSeverity:           \"\",\n  \tLastTransitionTime: v1.Time{Time: s\"2021-07-12 16:09:20 +0000 UTC\"},\n- \tReason:             \"NodeStartupTimeout\",\n+ \tReason:             \"\",\n- \tMessage:            \"Node failed to report startup in 1ms\",\n+ \tMessage:            \"\",\n  }\n" "controller"="machinehealthcheck" "name"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9"
I0712 16:09:21.525566   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:21.530083   10648 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-8scg8" "target"="test-mhc-h4zf9/test-mhc-ccdmj/test-mhc-machine-8scg8/test-mhc-node-mhp9d"
Cleaning up nodes, machines and infra machines.
I0712 16:09:21.555526   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:21.559489   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
I0712 16:09:21.578847   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-dcpv6" "namespace"="test-mhc-h4zf9" "count"=1
I0712 16:09:21.578946   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dcpv6" "namespace"="test-mhc-h4zf9" "descendants"="Worker machines: test-mhc-machine-8scg8" "indirect descendants count"=0
I0712 16:09:21.584511   10648 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-dcpv6" "namespace"="test-mhc-h4zf9" "count"=1
I0712 16:09:21.584585   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-dcpv6" "namespace"="test-mhc-h4zf9" "descendants"="Worker machines: test-mhc-machine-8scg8" "indirect descendants count"=0
I0712 16:09:21.588214   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ccdmj" "namespace"="test-mhc-h4zf9" 
=== RUN   TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted
I0712 16:09:21.722161   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
inframachine created: test-mhc-machine-infra-mmspt
I0712 16:09:21.765286   10648 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-ml6mv
E0712 16:09:21.776207   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"test-mhc-machine-8scg8\" in namespace \"test-mhc-h4zf9\": cannot find node with matching ProviderID" "controller"="machine" "name"="test-mhc-machine-8scg8" "namespace"="test-mhc-h4zf9"
I0712 16:09:21.788400   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:21.794227   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:21.795248   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:21.797060   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:21.798911   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:21.800743   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
... skipping 442 lines ...
I0712 16:09:22.784382   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.787983   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.788663   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.790791   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.792760   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-dcpv6" "machine"="test-mhc-machine-8scg8" "namespace"="test-mhc-h4zf9" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-mhp9d"}
I0712 16:09:22.792787   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.805746   10648 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-ml6mv" "target"="test-mhc-lwk7l/test-mhc-6kq7f/test-mhc-machine-ml6mv/"
I0712 16:09:22.822120   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
E0712 16:09:22.855425   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-8scg8\" not found" "controller"="machine" "name"="test-mhc-machine-8scg8" "namespace"="test-mhc-h4zf9"
E0712 16:09:22.888743   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqw24, got []"  "node"="test-mhc-node-gqw24"
E0712 16:09:22.888998   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqw24, got []"  "node"="test-mhc-node-gqw24"
node created: test-mhc-node-gqw24
E0712 16:09:22.889442   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-gqw24, got []"  "node"="test-mhc-node-gqw24"
I0712 16:09:22.916097   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.946887   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.949907   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.952475   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.956458   10648 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-ml6mv" "target"="test-mhc-lwk7l/test-mhc-6kq7f/test-mhc-machine-ml6mv/test-mhc-node-gqw24"
I0712 16:09:22.981813   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:22.987672   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:23.034220   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
Cleaning up nodes, machines and infra machines.
I0712 16:09:23.049125   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
I0712 16:09:23.055923   10648 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-ml6mv" "target"="test-mhc-lwk7l/test-mhc-6kq7f/test-mhc-machine-ml6mv/"
I0712 16:09:23.074082   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vvb7g" "namespace"="test-mhc-lwk7l" "descendants"="Worker machines: test-mhc-machine-ml6mv" "indirect descendants count"=1
E0712 16:09:23.087408   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-6kq7f\" not found" "controller"="machinehealthcheck" "name"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l"
I0712 16:09:23.091301   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-vvb7g" "namespace"="test-mhc-lwk7l" "descendants"="Worker machines: test-mhc-machine-ml6mv" "indirect descendants count"=1
--- FAIL: TestMachineHealthCheck_Reconcile (31.91s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.15s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.05s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.14s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy (0.74s)
... skipping 5 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away (0.00s)
        machinehealthcheck_controller_test.go:582: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy (3.34s)
    --- PASS: TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted (3.92s)
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- FAIL: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (2.44s)
        machinehealthcheck_controller_test.go:1149: 
            Timed out after 1.000s.
            expected
            	&v1alpha3.MachineHealthCheckStatus{ExpectedMachines:1, CurrentHealthy:1, RemediationsAllowed:1, ObservedGeneration:1, Targets:[]string{"test-mhc-machine-8scg8"}, Conditions:v1alpha3.Conditions{v1alpha3.Condition{Type:"RemediationAllowed", Status:"True", Severity:"", LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:63761702959, loc:(*time.Location)(0x29c7820)}}, Reason:"", Message:""}}}
            to match
            	&v1alpha3.MachineHealthCheckStatus{ExpectedMachines:1, CurrentHealthy:0, RemediationsAllowed:0, ObservedGeneration:1, Targets:[]string{"test-mhc-machine-8scg8"}, Conditions:v1alpha3.Conditions{v1alpha3.Condition{Type:"RemediationAllowed", Status:"True", Severity:"", LastTransitionTime:v1.Time{Time:time.Time{wall:0x0, ext:0, loc:(*time.Location)(nil)}}, Reason:"", Message:""}}}
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (1.52s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0712 16:09:23.117724   10648 machinehealthcheck_controller.go:416]  "msg"="expected a Cluster" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace
=== RUN   TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace
--- PASS: TestClusterToMachineHealthCheck (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_2_MachineHealthChecks_exists_for_the_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_the_same_namespace (0.00s)
    --- PASS: TestClusterToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_another_Cluster_in_another_namespace (0.00s)
=== RUN   TestMachineToMachineHealthCheck
=== RUN   TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine
E0712 16:09:23.120040   10648 machinehealthcheck_controller.go:445]  "msg"="expected a Machine" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace
=== RUN   TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace
--- PASS: TestMachineToMachineHealthCheck (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_the_object_passed_isn't_a_machine (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_2_MachineHealthChecks_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_does_not_match_labels_for_the_Machine_in_the_same_namespace (0.00s)
    --- PASS: TestMachineToMachineHealthCheck/when_a_MachineHealthCheck_matches_labels_for_the_Machine_in_another_namespace (0.00s)
=== RUN   TestNodeToMachineHealthCheck
=== RUN   TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node
E0712 16:09:23.122281   10648 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0712 16:09:23.123163   10648 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got []"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_two_Machines_exist_for_the_Node
E0712 16:09:23.123918   10648 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.00s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0712 16:09:23.127493   10648 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0712 16:09:23.128139   10648 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0712 16:09:23.130769   10648 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.01s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0712 16:09:23.143793   10648 machineset_controller.go:151]  "msg"="Failed to reconcile MachineSet" "error"="failed to calculate MachineSet's Status: failed to calculate status for MachineSet default/machineset1: invalid label key \"--$-invalid\": name part must consist of alphanumeric characters, '-', '_' or '.', and must start and end with an alphanumeric character (e.g. 'MyName',  or 'my.name',  or '123-abc', regex used for validation is '([A-Za-z0-9][-A-Za-z0-9_.]*)?[A-Za-z0-9]')" "machineset"="machineset1" "namespace"="default" 
--- PASS: TestMachineSetReconcile (0.00s)
    --- PASS: TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion (0.00s)
    --- PASS: TestMachineSetReconcile/records_event_if_reconcile_fails (0.00s)
=== RUN   TestMachineSetToMachines
=== RUN   TestMachineSetToMachines/should_return_empty_request_when_controller_is_set
=== RUN   TestMachineSetToMachines/should_return_nil_if_machine_has_no_owner_reference
... skipping 8 lines ...
--- PASS: TestAdoptOrphan (0.00s)
=== RUN   TestHasMatchingLabels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels
=== RUN   TestHasMatchingLabels/machine_set_has_empty_selector
=== RUN   TestHasMatchingLabels/machine_set_has_bad_selector
E0712 16:09:23.146710   10648 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 82 lines ...
I0712 16:09:23.168553   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
•I0712 16:09:23.171250   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:09:23.172604   10648 conversion.go:64]  "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="machine-test" "namespace"="default" "err"="cannot create a metadata client without a rest config"
I0712 16:09:23.174074   10648 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0712 16:09:23.174161   10648 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0712 16:09:23.175291   10648 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0712 16:09:23.177358   10648 machine_controller.go:494]  "msg"="Error creating a remote client while deleting Machine, won't retry" "error"="failed to create REST configuration for Cluster default/test-cluster: invalid configuration: no configuration has been provided" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node" 
•I0712 16:09:23.293102   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "creating"=2 "need"=2
I0712 16:09:23.293173   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:23.308457   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"md-wpldc-6657c7fddb-28m68\"" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:23.308590   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:23.353817   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"md-wpldc-6657c7fddb-2snqw\"" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
E0712 16:09:23.377331   10648 machineset_controller.go:151] controllers/MachineSet "msg"="Failed to reconcile MachineSet" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-wpldc-6657c7fddb\" not found" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
E0712 16:09:23.377415   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to patch MachineSet's Status: machinesets.cluster.x-k8s.io \"md-wpldc-6657c7fddb\" not found" "controller"="machineset" "name"="md-wpldc-6657c7fddb" "namespace"="md-test"
I0712 16:09:23.856163   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-vvb7g" "machine"="test-mhc-machine-ml6mv" "namespace"="test-mhc-lwk7l" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-gqw24"}
E0712 16:09:23.904524   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ml6mv\" not found" "controller"="machine" "name"="test-mhc-machine-ml6mv" "namespace"="test-mhc-lwk7l"
I0712 16:09:24.087768   10648 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-6kq7f" "namespace"="test-mhc-lwk7l" 
E0712 16:09:24.169866   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fpgbx/test-cluster-cqntl"
I0712 16:09:24.382857   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "creating"=3 "need"=3
I0712 16:09:24.382909   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.395830   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 3 with name \"md-wpldc-6657c7fddb-5k7dt\"" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.395899   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.412443   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 3 with name \"md-wpldc-6657c7fddb-txf5g\"" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.412519   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 3 of 3, ( spec.replicas(3) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.424644   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 3 of 3 with name \"md-wpldc-6657c7fddb-sxrpk\"" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" 
I0712 16:09:24.434854   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:09:24.434903   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
I0712 16:09:24.457962   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-cdfc6fd6c-mgrxf\"" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
E0712 16:09:24.521743   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.521809   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.634204   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.634270   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.634271   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.634316   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-mgrxf-wj54v, got []"  "node"="md-wpldc-cdfc6fd6c-mgrxf-wj54v"
E0712 16:09:24.663943   10648 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-wpldc-cdfc6fd6c-mgrxf-wj54v for machine md-test/md-wpldc-cdfc6fd6c-mgrxf: the cache is not started, can not read objects" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
I0712 16:09:24.692943   10648 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:09:24.693011   10648 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:09:24.701187   10648 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "machine"="md-wpldc-6657c7fddb-sxrpk"
I0712 16:09:24.737199   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:09:24.737355   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
I0712 16:09:24.755459   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-cdfc6fd6c-nsnf8\"" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
E0712 16:09:24.903535   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
E0712 16:09:24.903590   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
E0712 16:09:24.918794   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
E0712 16:09:24.918860   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
E0712 16:09:24.918862   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
E0712 16:09:24.918991   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-nsnf8-29rv5, got []"  "node"="md-wpldc-cdfc6fd6c-nsnf8-29rv5"
I0712 16:09:25.099853   10648 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:09:25.099910   10648 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:09:25.106921   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:25.106977   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:25.185837   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:25.185904   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
... skipping 2 lines ...
I0712 16:09:25.276401   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-5k7dt" "namespace"="md-test" 
I0712 16:09:25.284975   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:09:25.285049   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
I0712 16:09:25.303512   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-cdfc6fd6c-p4g5j\"" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" 
I0712 16:09:25.306333   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-txf5g" "namespace"="md-test" 
I0712 16:09:25.306378   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-txf5g" "namespace"="md-test" 
E0712 16:09:25.354187   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-mgrxf\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-mgrxf" "namespace"="md-test"
E0712 16:09:25.413012   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
E0712 16:09:25.413093   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
E0712 16:09:25.417465   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
E0712 16:09:25.417523   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
E0712 16:09:25.417716   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
E0712 16:09:25.417800   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-cdfc6fd6c-p4g5j-jqpw2, got []"  "node"="md-wpldc-cdfc6fd6c-p4g5j-jqpw2"
I0712 16:09:25.496576   10648 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0712 16:09:25.497381   10648 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0712 16:09:25.502653   10648 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-wpldc-6657c7fddb" "namespace"="md-test" "machine"="md-wpldc-6657c7fddb-txf5g"
I0712 16:09:25.812723   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0712 16:09:25.812792   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
I0712 16:09:25.836059   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-74d45c49c5-g6k56\"" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
E0712 16:09:25.901347   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
E0712 16:09:25.901393   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
E0712 16:09:26.022128   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
E0712 16:09:26.022200   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
E0712 16:09:26.022248   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
E0712 16:09:26.022307   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-g6k56-phht2, got []"  "node"="md-wpldc-74d45c49c5-g6k56-phht2"
I0712 16:09:26.094733   10648 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0712 16:09:26.094792   10648 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:09:26.138321   10648 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "machine"="md-wpldc-cdfc6fd6c-p4g5j"
I0712 16:09:26.168040   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0712 16:09:26.168110   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
I0712 16:09:26.181613   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-74d45c49c5-w5llq\"" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
E0712 16:09:26.277124   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
E0712 16:09:26.277157   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
E0712 16:09:26.280758   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
E0712 16:09:26.280820   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
E0712 16:09:26.281075   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
E0712 16:09:26.281143   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-w5llq-cnx5b, got []"  "node"="md-wpldc-74d45c49c5-w5llq-cnx5b"
I0712 16:09:26.327955   10648 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0712 16:09:26.328102   10648 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0712 16:09:26.335275   10648 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-wpldc-cdfc6fd6c" "namespace"="md-test" "machine"="md-wpldc-cdfc6fd6c-mgrxf"
I0712 16:09:26.399656   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0712 16:09:26.399715   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
I0712 16:09:26.421234   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-wpldc-74d45c49c5-h6d9k\"" "machineset"="md-wpldc-74d45c49c5" "namespace"="md-test" 
E0712 16:09:26.431613   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
E0712 16:09:26.601741   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-h6d9k-pwhq6, got []"  "node"="md-wpldc-74d45c49c5-h6d9k-pwhq6"
E0712 16:09:26.601838   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-h6d9k-pwhq6, got []"  "node"="md-wpldc-74d45c49c5-h6d9k-pwhq6"
E0712 16:09:26.602082   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-h4zf9/test-cluster-dcpv6"
E0712 16:09:26.607608   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-h6d9k-pwhq6, got []"  "node"="md-wpldc-74d45c49c5-h6d9k-pwhq6"
E0712 16:09:26.607670   10648 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-wpldc-74d45c49c5-h6d9k-pwhq6, got []"  "node"="md-wpldc-74d45c49c5-h6d9k-pwhq6"
I0712 16:09:26.630207   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-wpldc-74d45c49c5,md-wpldc-cdfc6fd6c;Worker machines: md-wpldc-6657c7fddb-txf5g,md-wpldc-cdfc6fd6c-nsnf8,md-wpldc-cdfc6fd6c-mgrxf,md-wpldc-74d45c49c5-w5llq,md-wpldc-74d45c49c5-g6k56,md-wpldc-74d45c49c5-h6d9k,md-wpldc-6657c7fddb-28m68,md-wpldc-6657c7fddb-2snqw,md-wpldc-6657c7fddb-5k7dt" "indirect descendants count"=11
I0712 16:09:26.636023   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-wpldc-74d45c49c5,md-wpldc-cdfc6fd6c;Worker machines: md-wpldc-6657c7fddb-txf5g,md-wpldc-cdfc6fd6c-nsnf8,md-wpldc-cdfc6fd6c-mgrxf,md-wpldc-74d45c49c5-w5llq,md-wpldc-74d45c49c5-g6k56,md-wpldc-74d45c49c5-h6d9k,md-wpldc-6657c7fddb-28m68,md-wpldc-6657c7fddb-2snqw,md-wpldc-6657c7fddb-5k7dt" "indirect descendants count"=11
••E0712 16:09:26.767522   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-zjf2b\" not found" "controller"="cluster" "name"="test1-zjf2b" "namespace"="default"
I0712 16:09:27.437300   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:27.437369   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:27.443177   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:27.443239   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:27.444025   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-6657c7fddb-5k7dt" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0712 16:09:27.476398   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-6657c7fddb-txf5g" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
I0712 16:09:27.516543   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-cdfc6fd6c-mgrxf" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-wpldc-cdfc6fd6c-mgrxf-wj54v"}
E0712 16:09:27.630907   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
•I0712 16:09:27.892283   10648 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jg2cg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:09:28.014544   10648 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-jg2cg" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:09:28.037509   10648 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-jg2cg" "namespace"="default"
I0712 16:09:28.631634   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-6657c7fddb-5k7dt" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0712 16:09:28.660761   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-wpldc-6657c7fddb-5k7dt\" not found" "controller"="machine" "name"="md-wpldc-6657c7fddb-5k7dt" "namespace"="md-test"
E0712 16:09:29.066623   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
•I0712 16:09:29.661302   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-6657c7fddb-txf5g" "namespace"="md-test" "cause"="cluster is being deleted" "node"=null
E0712 16:09:29.694260   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-wpldc-6657c7fddb-txf5g\" not found" "controller"="machine" "name"="md-wpldc-6657c7fddb-txf5g" "namespace"="md-test"
E0712 16:09:30.080502   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lwk7l/test-cluster-vvb7g"
E0712 16:09:30.096189   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-ldmbg\" not found" "controller"="cluster" "name"="test3-ldmbg" "namespace"="default"
I0712 16:09:30.695012   10648 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-wpldc-cdfc6fd6c-mgrxf" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-wpldc-cdfc6fd6c-mgrxf-wj54v"}
E0712 16:09:30.726594   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-wpldc-cdfc6fd6c-mgrxf\" not found" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-mgrxf" "namespace"="md-test"
E0712 16:09:31.096937   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
E0712 16:09:31.756968   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-g6k56\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-g6k56" "namespace"="md-test"
E0712 16:09:32.107885   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
•E0712 16:09:32.785186   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-w5llq\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-w5llq" "namespace"="md-test"
I0712 16:09:33.108597   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-wpldc-74d45c49c5,md-wpldc-cdfc6fd6c;Worker machines: md-wpldc-6657c7fddb-2snqw,md-wpldc-74d45c49c5-g6k56,md-wpldc-cdfc6fd6c-nsnf8,md-wpldc-74d45c49c5-w5llq,md-wpldc-74d45c49c5-h6d9k,md-wpldc-6657c7fddb-28m68" "indirect descendants count"=8
E0712 16:09:33.113698   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:33.807309   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
E0712 16:09:34.124150   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
•I0712 16:09:34.812555   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:34.812604   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:34.816776   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:34.816818   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
E0712 16:09:34.817404   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-ljk5f\" for machine \"test-mhc-machine-dkfwv\" in namespace \"test-mhc-lgd87\": Cluster.cluster.x-k8s.io \"test-cluster-ljk5f\" not found" "controller"="machine" "name"="test-mhc-machine-dkfwv" "namespace"="test-mhc-lgd87"
E0712 16:09:35.125042   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:35.822634   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-g6k56\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-g6k56" "namespace"="md-test"
E0712 16:09:36.134220   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
E0712 16:09:36.828847   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-w5llq\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-w5llq" "namespace"="md-test"
E0712 16:09:37.135059   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:37.838206   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
E0712 16:09:38.136017   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
I0712 16:09:38.842979   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:38.843046   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:38.846754   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:38.846798   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
E0712 16:09:38.850832   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-g6k56\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-g6k56" "namespace"="md-test"
E0712 16:09:39.136874   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:39.865498   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-w5llq\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-w5llq" "namespace"="md-test"
I0712 16:09:40.137683   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-wpldc-74d45c49c5,md-wpldc-cdfc6fd6c;Worker machines: md-wpldc-cdfc6fd6c-nsnf8,md-wpldc-74d45c49c5-w5llq,md-wpldc-74d45c49c5-h6d9k,md-wpldc-6657c7fddb-28m68,md-wpldc-6657c7fddb-2snqw,md-wpldc-74d45c49c5-g6k56" "indirect descendants count"=8
E0712 16:09:40.138308   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
E0712 16:09:40.870287   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
E0712 16:09:41.139064   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:41.875252   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-g6k56\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-g6k56" "namespace"="md-test"
E0712 16:09:42.139928   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
I0712 16:09:42.880334   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:42.880378   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:42.884615   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:42.884663   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:42.903024   10648 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7d6sz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0712 16:09:42.913186   10648 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-7d6sz" "namespace"="default" 
E0712 16:09:42.926523   10648 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-7d6sz" "namespace"="default"
E0712 16:09:43.140845   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:43.931897   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-w5llq\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-w5llq" "namespace"="md-test"
E0712 16:09:44.141772   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
E0712 16:09:44.937559   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-cdfc6fd6c-nsnf8\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-cdfc6fd6c-nsnf8" "namespace"="md-test"
E0712 16:09:45.142712   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"
E0712 16:09:45.943178   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-g6k56\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-g6k56" "namespace"="md-test"
E0712 16:09:46.143585   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
I0712 16:09:46.957688   10648 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-7d6sz" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0712 16:09:46.957998   10648 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-7d6sz" "namespace"="default" "noderef"="id-node-1"
E0712 16:09:46.970909   10648 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-7d6sz" "namespace"="default"
I0712 16:09:47.144261   10648 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-wpldc-74d45c49c5,md-wpldc-cdfc6fd6c;Worker machines: md-wpldc-6657c7fddb-2snqw,md-wpldc-74d45c49c5-g6k56,md-wpldc-cdfc6fd6c-nsnf8,md-wpldc-74d45c49c5-w5llq,md-wpldc-74d45c49c5-h6d9k,md-wpldc-6657c7fddb-28m68" "indirect descendants count"=8
E0712 16:09:47.144860   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-2l65s: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-2l65s" "namespace"="default"
I0712 16:09:47.976302   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:47.976354   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-28m68" "namespace"="md-test" 
I0712 16:09:47.980199   10648 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
I0712 16:09:47.980234   10648 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-wpldc-6657c7fddb-2snqw" "namespace"="md-test" 
E0712 16:09:47.984161   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-wpldc-74d45c49c5-w5llq\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-wpldc-74d45c49c5-w5llq" "namespace"="md-test"
E0712 16:09:48.149572   10648 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-jg2cg: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-jg2cg" "namespace"="default"

------------------------------
• [SLOW TEST:14.063 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 4 lines ...
I0712 16:09:48.286401   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-rdnqr-gl5lw\"" "machineset"="ms-rdnqr" "namespace"="ms-test" 
I0712 16:09:48.286517   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-rdnqr" "namespace"="ms-test" 
I0712 16:09:48.302854   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-rdnqr-9t62h\"" "machineset"="ms-rdnqr" "namespace"="ms-test" 
I0712 16:09:48.405601   10648 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-rdnqr" "namespace"="ms-test" "creating"=1 "need"=2
I0712 16:09:48.405649   10648 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-rdnqr" "namespace"="ms-test" 
I0712 16:09:48.419338   10648 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-rdnqr-hkbjb\"" "machineset"="ms-rdnqr" "namespace"="ms-test" 
E0712 16:09:48.587430   10648 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-rdnqr-hkbjb-wxl4d for machine ms-test/ms-rdnqr-hkbjb: the cache is not started, can not read objects" "machineset"="ms-rdnqr" "namespace"="ms-test" 
E0712 16:09:48.801956   10648 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="ms-test/test-cluster"
•

Ran 16 of 16 Specs in 25.656 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (25.66s)
FAIL
Tearing down test suite
I0712 16:09:48.805430   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0712 16:09:48.805446   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0712 16:09:48.805485   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:09:48.805507   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0712 16:09:48.805535   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0712 16:09:48.806122   10648 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0712 16:09:48.806742   10648 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:09:48.844432   10648 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:39465/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1333&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:39465: connect: connection refused
E0712 16:09:48.844490   10648 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:39465/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1333&timeout=10s&timeoutSeconds=354&watch=true: dial tcp 127.0.0.1:39465: connect: connection refused
FAIL	sigs.k8s.io/cluster-api/controllers	76.096s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
--- PASS: TestCloneTemplateResourceNotFound (0.00s)
... skipping 255 lines ...
I0712 16:08:46.575881   10928 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"addons.cluster.x-k8s.io","Version":"v1alpha3","Kind":"ClusterResourceSet"} "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0712 16:08:46.575908   10928 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0712 16:08:46.576166   10928 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0712 16:08:46.608592   10928 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0712 16:08:46.609109   10928 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=38969
I0712 16:08:46.609461   10928 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
E0712 16:08:48.731905   10928 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-cs2gp/test-cluster"
•E0712 16:08:49.230656   10928 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-rrzqh/test-cluster"
•E0712 16:08:49.805168   10928 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:46077/?timeout=50ms: dial tcp 127.0.0.1:46077: connect: connection refused"  "cluster"="cluster-cache-test-rbqww/test-cluster"
•I0712 16:08:50.081426   10928 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","selector":{},"template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{}}}
I0712 16:08:50.290736   10928 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0712 16:08:50.290806   10928 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0712 16:08:50.290889   10928 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0712 16:08:50.820482   10928 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0712 16:08:50.858469   10928 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="cluster" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0712 16:08:50.959078   10928 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0712 16:08:50.959149   10928 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0712 16:08:51.110527   10928 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
I0712 16:08:51.110608   10928 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0712 16:08:51.170344   10928 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:39561/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=143&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:39561: connect: connection refused


Ran 5 of 5 Specs in 17.385 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.39s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.611s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 155 lines ...
=== RUN   TestPaths/empty_input_makes_for_empty_output
--- PASS: TestPaths (0.00s)
    --- PASS: TestPaths/basic_check (0.00s)
    --- PASS: TestPaths/empty_input_makes_for_empty_output (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/api/v1alpha3	0.110s
FAIL	sigs.k8s.io/cluster-api/controlplane/kubeadm/controllers [build failed]
I0712 16:08:57.533152   11607 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:08:57.533326   11607 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:08:57.533363   11607 webhook.go:123] controller-runtime/builder "msg"="Registering a validating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Cluster"} "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:08:57.533387   11607 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-cluster-x-k8s-io-v1alpha3-cluster"
I0712 16:08:57.533551   11607 webhook.go:102] controller-runtime/builder "msg"="Registering a mutating webhook"  "GVK"={"Group":"cluster.x-k8s.io","Version":"v1alpha3","Kind":"Machine"} "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
I0712 16:08:57.533573   11607 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/mutate-cluster-x-k8s-io-v1alpha3-machine"
... skipping 51 lines ...
==================================
Random Seed: 1626106124
Will run 7 of 7 specs

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

•••••••
Ran 7 of 7 Specs in 0.000 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 271 lines ...
    --- PASS: TestUpdateKubeProxyImageInfo/returns_error_if_image_repository_is_invalid (0.00s)
    --- PASS: TestUpdateKubeProxyImageInfo/does_not_update_image_repository_when_no_kube-proxy_update_is_requested (0.00s)
=== RUN   TestRemoveMachineFromKubeadmConfigMap
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_find_kubeadm-config_for_Kubernetes_version_<_1.22.0
E0712 16:09:00.081738   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:09:08.404800   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:09:17.390824   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:09:28.521147   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:09:44.994558   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:09:58.003256   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:10:15.650761   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:10:36.574216   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:11:07.590854   11607 workload_cluster.go:325]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0712 16:11:52.748046   11607 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.68s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 71 lines ...
=== RUN   TestClusterStatus/returns_cluster_status
=== RUN   TestClusterStatus/returns_cluster_status_with_kubeadm_config
--- PASS: TestClusterStatus (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status (0.00s)
    --- PASS: TestClusterStatus/returns_cluster_status_with_kubeadm_config (0.00s)
PASS
E0712 16:11:52.756813   11607 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:11:52.756862   11607 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-870835647/tls.crt: no such file or directory"  
E0712 16:11:52.756878   11607 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:11:52.756891   11607 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-870835647/tls.crt: no such file or directory"  
I0712 16:11:52.757142   11607 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
ok  	sigs.k8s.io/cluster-api/controlplane/kubeadm/internal	188.524s
=== RUN   TestEtcdMembers_WithErrors
--- PASS: TestEtcdMembers_WithErrors (0.00s)
=== RUN   TestEtcdMembers_WithSuccess
--- PASS: TestEtcdMembers_WithSuccess (0.00s)
... skipping 288 lines ...
I0712 16:09:03.942337   11771 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0712 16:09:03.942689   11771 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:09:04.043136   11771 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0712 16:09:04.144870   11771 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0712 16:09:04.144944   11771 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0712 16:09:04.231999   11771 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-5gqi1q"} 
E0712 16:09:04.285453   11771 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•I0712 16:09:05.362145   11771 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-l2rdz4"} 
•E0712 16:09:05.408947   11771 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
E0712 16:09:16.524056   11771 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"

------------------------------
• Failure [11.118 seconds]
ClusterResourceSet Reconciler
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:40
  Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources [It]
... skipping 8 lines ...
------------------------------
STEP: Creating the Cluster
STEP: Creating the remote Cluster kubeconfig
STEP: Creating a Secret and a ConfigMap with ConfigMap in their data field
STEP: Verifying ClusterResourceSetBinding is created with cluster owner reference
STEP: Deleting the Kubeconfigsecret
E0712 16:09:17.685759   11771 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusterresourcesets.addons.cluster.x-k8s.io \"test-clusterresourceset\" not found" "controller"="clusterresourceset" "name"="test-clusterresourceset" "namespace"="default"
•E0712 16:09:18.717276   11771 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"
•I0712 16:09:19.745511   11771 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0712 16:09:19.745591   11771 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0712 16:09:19.745657   11771 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0712 16:09:19.745965   11771 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0712 16:09:19.746025   11771 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-116189406/tls.crt: no such file or directory"  
E0712 16:09:19.748389   11771 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"



Summarizing 1 Failure:

[Fail] ClusterResourceSet Reconciler [It] Should reconcile a ClusterResourceSet when a resource is created that is part of ClusterResourceSet resources 
/home/prow/go/src/sigs.k8s.io/cluster-api/exp/addons/controllers/clusterresourceset_controller_test.go:307

Ran 5 of 5 Specs in 30.379 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (30.38s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	30.527s
?   	sigs.k8s.io/cluster-api/exp/addons/controllers/predicates	[no test files]
=== RUN   TestMachinePoolDefault
=== RUN   TestMachinePoolDefault/for_MachinePool
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-create
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-update
=== RUN   TestMachinePoolDefault/for_MachinePool/validate-on-delete
... skipping 58 lines ...
    --- PASS: TestReconcileMachinePoolBootstrap/new_machinepool,_no_bootstrap_config_or_data (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_data_should_not_change (0.00s)
    --- PASS: TestReconcileMachinePoolBootstrap/existing_machinepool,_bootstrap_provider_is_to_not_ready (0.00s)
=== RUN   TestReconcileMachinePoolInfrastructure
=== RUN   TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready
=== RUN   TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed
E0712 16:08:54.039349   11958 machinepool_controller_phases.go:237]  "msg"="MachinePool infrastructure reference has been deleted after being ready, setting failure state" "error"="could not find infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureConfig \"infra-config1\" for MachinePool \"machinepool-test\" in namespace \"default\", requeuing: failed to retrieve InfrastructureConfig external object \"default\"/\"infra-config1\": infrastructureconfigs.infrastructure.cluster.x-k8s.io \"infra-config1\" not found" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
=== RUN   TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused
--- PASS: TestReconcileMachinePoolInfrastructure (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/new_machinepool,_infrastructure_config_ready (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/ready_bootstrap,_infra,_and_nodeRef,_machinepool_is_running,_infra_object_is_deleted,_expect_failed (0.00s)
    --- PASS: TestReconcileMachinePoolInfrastructure/infrastructure_ref_is_paused (0.00s)
=== RUN   TestMachinePoolFinalizer
... skipping 92 lines ...
•I0712 16:09:07.810900   11958 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:09:07.849898   11958 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:09:07.852189   11958 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0712 16:09:07.871126   11958 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:09:07.913592   11958 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0712 16:09:07.914230   11958 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}}}
•E0712 16:09:07.916361   11958 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:09:07.916404   11958 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-163490653/tls.crt: no such file or directory"  
E0712 16:09:07.916423   11958 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0712 16:09:07.916442   11958 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-163490653/tls.crt: no such file or directory"  
I0712 16:09:07.916654   11958 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


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


Ran 14 of 14 Specs in 8.447 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (8.45s)
=== RUN   TestToUnstructured
=== RUN   TestToUnstructured/with_a_typed_object
=== RUN   TestToUnstructured/with_an_unstructured_object
--- PASS: TestToUnstructured (0.00s)
    --- PASS: TestToUnstructured/with_a_typed_object (0.00s)
... skipping 81 lines ...
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#01 (0.00s)
    --- PASS: TestToUnstructured/returns_error_for_invalid_yaml#02 (0.00s)
=== RUN   TestFromUnstructured
--- PASS: TestFromUnstructured (0.00s)
PASS
ok  	sigs.k8s.io/cluster-api/util/yaml	0.038s
FAIL
make: *** [Makefile:116: test] Error 2
+ EXIT_VALUE=2
+ set +o xtrace