This job view page is being replaced by Spyglass soon. Check out the new job view.
PRsbueringer: ✨ v0.3.x: KCP: block mgmt cluster updates to v1.22.0
ResultFAILURE
Tests 0 failed / 0 succeeded
Started2021-07-28 16:05
Elapsed4m52s
Revision3059590700a6024c572529791537112ed60df260
Refs 5013

No Test Failures!


Error lines from build-log.txt

... skipping 777 lines ...
I0728 16:07:52.015052    8531 server.go:121] controller-runtime/webhook "msg"="registering webhook"  "path"="/validate-addons-cluster-x-k8s-io-v1alpha3-clusterresourceset"
I0728 16:07:52.015338    8531 server.go:141] controller-runtime/webhook/webhooks "msg"="starting webhook server"  
I0728 16:07:52.016836    8531 certwatcher.go:127] controller-runtime/certwatcher "msg"="Updated current TLS certificate"  
I0728 16:07:52.017081    8531 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=39157
I0728 16:07:52.017257    8531 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0728 16:07:52.547242    8531 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" 
•E0728 16:07:52.562756    8531 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
I0728 16:07:52.562799    8531 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0728 16:07:52.562804    8531 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-487381090/tls.crt: no such file or directory"  


Ran 1 of 1 Specs in 13.591 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (13.59s)
PASS
ok  	sigs.k8s.io/cluster-api/bootstrap/kubeadm/controllers	63.606s
=== RUN   TestNewInitControlPlaneAdditionalFileEncodings
--- PASS: TestNewInitControlPlaneAdditionalFileEncodings (0.00s)
=== RUN   TestNewInitControlPlaneCommands
... skipping 310 lines ...
=== RUN   Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined
--- PASS: Test_clusterctlClient_GetProvidersConfig (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers (0.00s)
    --- PASS: Test_clusterctlClient_GetProvidersConfig/Returns_default_providers_and_custom_providers_if_defined (0.00s)
=== RUN   Test_clusterctlClient_GetProviderComponents
=== RUN   Test_clusterctlClient_GetProviderComponents/Pass
=== RUN   Test_clusterctlClient_GetProviderComponents/Fail
--- PASS: Test_clusterctlClient_GetProviderComponents (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Pass (0.00s)
    --- PASS: Test_clusterctlClient_GetProviderComponents/Fail (0.00s)
=== RUN   Test_getComponentsByName_withEmptyVariables
--- PASS: Test_getComponentsByName_withEmptyVariables (0.00s)
=== RUN   Test_clusterctlClient_templateOptionsToVariables
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_template_options)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_KubernetesVersion_from_env_variables)
=== RUN   Test_clusterctlClient_templateOptionsToVariables/pass_(using_defaults_for_machine_counts)
... skipping 1398 lines ...
I0728 16:07:24.027697   10533 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinehealthcheck" 
I0728 16:07:24.027728   10533 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinehealthcheck" "worker count"=1
I0728 16:07:24.032706   10533 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":{}}}
I0728 16:07:24.032790   10533 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"controlPlaneEndpoint":{"host":"","port":0}},"status":{"infrastructureReady":false,"controlPlaneInitialized":false}}}
I0728 16:07:24.032823   10533 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0728 16:07:24.032858   10533 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
2021/07/28 16:07:24 http: TLS handshake error from 127.0.0.1:34356: 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
I0728 16:07:24.424398   10533 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"
I0728 16:07:24.431335   10533 cluster_controller_phases.go:76]  "msg"="Could not find external object for cluster, requeuing" "cluster"="test-cluster" "namespace"="test-namespace" "refGroupVersionKind"={"Group":"infrastructure.cluster.x-k8s.io","Version":"v1alpha3","Kind":"InfrastructureMachine"} "refName"="test"
... skipping 105 lines ...
    --- PASS: TestReconcileBootstrap/existing_machine,_machineset_owner_and_version_v1alpha2,_and_ownerref_updated (0.00s)
=== RUN   TestReconcileInfrastructure
=== RUN   TestReconcileInfrastructure/new_machine,_infrastructure_config_ready
I0728 16:07:24.498841   10533 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
I0728 16:07:24.500435   10533 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"
E0728 16:07:24.500851   10533 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
I0728 16:07:24.501330   10533 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
I0728 16:07:24.968785   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={}
E0728 16:07:25.069295   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
I0728 16:07:25.125094   10533 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm" "GroupVersionKind"="bootstrap.cluster.x-k8s.io/v1alpha3, Kind=BootstrapMachine"
I0728 16:07:25.125186   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"bootstrap.cluster.x-k8s.io/v1alpha3","kind":"BootstrapMachine"}}
I0728 16:07:25.234211   10533 tracker.go:55] controllers/Machine "msg"="Adding watcher on external object" "machine"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm" "GroupVersionKind"="infrastructure.cluster.x-k8s.io/v1alpha3, Kind=InfrastructureMachine"
I0728 16:07:25.234309   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machine" "source"={"Type":{"apiVersion":"infrastructure.cluster.x-k8s.io/v1alpha3","kind":"InfrastructureMachine"}}
I0728 16:07:25.334859   10533 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm" "noderef"="node-1"
E0728 16:07:25.342152   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0728 16:07:25.342207   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="node-1"
E0728 16:07:25.410963   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"machine-created-zz4wb\" in namespace \"test-machine-watches-8lzjm\": cannot find node with matching ProviderID" "controller"="machine" "name"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm"
E0728 16:07:26.415157   10533 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-zz4wb\" in namespace \"test-machine-watches-8lzjm\", requeuing: requeue in 1s"  
E0728 16:07:26.431250   10533 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-zz4wb\" in namespace \"test-machine-watches-8lzjm\", requeuing: requeue in 1s, no matching Node for Machine \"machine-created-zz4wb\" in namespace \"test-machine-watches-8lzjm\": cannot find node with matching ProviderID]" "controller"="machine" "name"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm"
--- PASS: TestWatches (2.00s)
=== 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
I0728 16:07:26.686772   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-7gfqc" "namespace"="test-machine-watches-8lzjm" "count"=1
I0728 16:07:26.686842   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-7gfqc" "namespace"="test-machine-watches-8lzjm" "descendants"="Worker machines: machine-created-zz4wb" "indirect descendants count"=0
I0728 16:07:26.709429   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="machine-reconcile-7gfqc" "namespace"="test-machine-watches-8lzjm" "count"=1
I0728 16:07:26.709494   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="machine-reconcile-7gfqc" "namespace"="test-machine-watches-8lzjm" "descendants"="Worker machines: machine-created-zz4wb" "indirect descendants count"=0
I0728 16:07:27.432466   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-7gfqc" "machine"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm" "cause"="cluster is being deleted" "node"={"kind":"Node","name":"node-1","uid":"d341a3a8-7619-44ef-81d5-75cd047082d3","apiVersion":"v1"}
E0728 16:07:27.477322   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-zz4wb\" not found" "controller"="machine" "name"="machine-created-zz4wb" "namespace"="test-machine-watches-8lzjm"
E0728 16:07:28.522737   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[retrieved empty dataSecretName from bootstrap provider for Machine \"machine-created-66cdz\" in namespace \"default\", error creating client and cache for remote cluster: error fetching REST client config for remote cluster \"default/machine-reconcile-w694f\": failed to retrieve kubeconfig secret for Cluster default/machine-reconcile-w694f: secrets \"machine-reconcile-w694f-kubeconfig\" not found]" "controller"="machine" "name"="machine-created-66cdz" "namespace"="default"
I0728 16:07:29.523348   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-w694f" "machine"="machine-created-66cdz" "namespace"="default" "cause"="noderef is nil" "node"=null
I0728 16:07:29.557674   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-w694f" "machine"="machine-created-66cdz" "namespace"="default" "cause"="noderef is nil" "node"=null
I0728 16:07:29.585788   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="machine-reconcile-w694f" "machine"="machine-created-66cdz" "namespace"="default" "cause"="noderef is nil" "node"=null
E0728 16:07:29.619223   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"machine-created-66cdz\" not found" "controller"="machine" "name"="machine-created-66cdz" "namespace"="default"
--- PASS: TestMachine_Reconcile (3.13s)
    --- PASS: TestMachine_Reconcile/reconcile_create (3.13s)
=== 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 3 lines ...
=== RUN   TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta
I0728 16:07:29.641712   10533 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"
I0728 16:07:29.641885   10533 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
I0728 16:07:29.661955   10533 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"
I0728 16:07:29.663295   10533 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine3" "namespace"="default" 
E0728 16:07:29.665630   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"machine-reconcile-w694f\" not found" "controller"="cluster" "name"="machine-reconcile-w694f" "namespace"="default"
=== RUN   TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_has_a_controller_owner
I0728 16:07:29.668560   10533 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"
I0728 16:07:29.668727   10533 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine4" "namespace"="default" 
--- PASS: TestMachineOwnerReference (0.04s)
    --- PASS: TestMachineOwnerReference/should_add_owner_reference_to_machine_referencing_a_cluster_with_correct_type_meta (0.02s)
    --- PASS: TestMachineOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_set (0.01s)
... skipping 122 lines ...
    --- PASS: TestMachineDeploymentSyncStatus/machine_set_failed (0.00s)
=== RUN   TestMachineHealthCheck_Reconcile
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist
I0728 16:07:29.920957   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tgx7n" "namespace"="test-mhc-s4q9v" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value
I0728 16:07:29.967601   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0728 16:07:29.969099   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Cluster.cluster.x-k8s.io \"test-cluster-bzd78\" not found"  "cluster"="test-mhc-s4q9v/test-cluster-bzd78"
E0728 16:07:29.973988   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="[MachineHealthCheck.cluster.x-k8s.io \"test-mhc-tgx7n\" not found, machinehealthchecks.cluster.x-k8s.io \"test-mhc-tgx7n\" not found]" "controller"="machinehealthcheck" "name"="test-mhc-tgx7n" "namespace"="test-mhc-s4q9v"
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist
I0728 16:07:30.974270   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xcmsm" "namespace"="test-mhc-wqjsv" 
I0728 16:07:30.974384   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-tgx7n" "namespace"="test-mhc-s4q9v" 
I0728 16:07:30.974414   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-hkl55" "namespace"="test-mhc-qpm25" 
I0728 16:07:30.974445   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kx4k6" "namespace"="test-mhc-qv496" 
I0728 16:07:30.991199   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 16:07:31.024955   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kx4k6" "namespace"="test-mhc-qv496" 
I0728 16:07:31.025566   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kx4k6" "namespace"="test-mhc-qv496" 
I0728 16:07:31.051482   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-kx4k6" "namespace"="test-mhc-qv496" 
=== RUN   TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones
E0728 16:07:31.062317   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-qv496/test-cluster-xv6xx"
E0728 16:07:31.064967   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test-cluster-xv6xx\" not found" "controller"="cluster" "name"="test-cluster-xv6xx" "namespace"="test-mhc-qv496"
I0728 16:07:31.184791   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwsn5" "namespace"="test-mhc-7ts7k" 
I0728 16:07:31.202437   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 16:07:31.322677   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwsn5" "namespace"="test-mhc-7ts7k" 
I0728 16:07:31.327602   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwsn5" "namespace"="test-mhc-7ts7k" 
E0728 16:07:31.390445   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-7ts7k/test-cluster-m7h8v"
=== RUN   TestMachineHealthCheck_Reconcile/it_doesn't_mark_anything_unhealthy_when_all_Machines_are_healthy
I0728 16:07:31.395325   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-dwsn5" "namespace"="test-mhc-7ts7k" 
I0728 16:07:31.416461   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
inframachine created: test-mhc-machine-infra-knn45
I0728 16:07:31.462410   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
machine created: test-mhc-machine-wr9mx
I0728 16:07:31.487803   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.488119   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.508173   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.508569   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.521053   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.521436   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.537833   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.538143   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.554796   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.555126   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.566401   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.566698   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
node created: test-mhc-node-6j8m9
E0728 16:07:31.571387   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6j8m9, got []"  "node"="test-mhc-node-6j8m9"
E0728 16:07:31.571387   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6j8m9"
I0728 16:07:31.573298   10533 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms" "noderef"="test-mhc-node-6j8m9"
E0728 16:07:31.579007   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6j8m9, got []"  "node"="test-mhc-node-6j8m9"
E0728 16:07:31.579069   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-6j8m9, got []"  "node"="test-mhc-node-6j8m9"
E0728 16:07:31.579756   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6j8m9"
E0728 16:07:31.579894   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-6j8m9"
I0728 16:07:31.589491   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
inframachine created: test-mhc-machine-infra-xsp9l
machine created: test-mhc-machine-2rkgp
I0728 16:07:31.639481   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.645120   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.646711   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
... skipping 33 lines ...
I0728 16:07:31.753226   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.755481   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.756542   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.757559   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.759676   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.760842   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.761197   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.772307   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.772796   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.774871   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.775263   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.794128   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.800837   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.814006   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.814469   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.819103   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.819570   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
I0728 16:07:31.839172   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.839669   10533 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-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
E0728 16:07:31.842379   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g5c9p, got []"  "node"="test-mhc-node-g5c9p"
node created: test-mhc-node-g5c9p
E0728 16:07:31.843031   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g5c9p"
I0728 16:07:31.843813   10533 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms" "noderef"="test-mhc-node-g5c9p"
E0728 16:07:31.876201   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g5c9p"
E0728 16:07:31.876256   10533 machine_controller.go:685] controllers/Machine "msg"="Unable to retrieve machine from node" "error"="no matching Machine"  "node"="test-mhc-node-g5c9p"
E0728 16:07:31.876286   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g5c9p, got []"  "node"="test-mhc-node-g5c9p"
E0728 16:07:31.876329   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-g5c9p, got []"  "node"="test-mhc-node-g5c9p"
I0728 16:07:31.876808   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.916204   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
Cleaning up nodes, machines and infra machines.
I0728 16:07:31.926550   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.927102   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.995044   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:31.995609   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lxrms/test-mhc-h6m6l/test-mhc-machine-wr9mx/"
I0728 16:07:31.996105   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-lxrms/test-mhc-h6m6l/test-mhc-machine-2rkgp/"
E0728 16:07:32.019966   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-lxrms/test-cluster-988jc"
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_there_is_one_unhealthy_Machine
E0728 16:07:32.042905   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-h6m6l\" not found" "controller"="machinehealthcheck" "name"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms"
inframachine created: test-mhc-machine-infra-vn4q8
machine created: test-mhc-machine-nlbx8
E0728 16:07:32.085681   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-machine-watches-8lzjm/machine-reconcile-7gfqc"
E0728 16:07:32.093497   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:33.043230   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-h6m6l" "namespace"="test-mhc-lxrms" 
I0728 16:07:33.043323   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:33.064903   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
E0728 16:07:33.129799   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:33.175071   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-nlbx8/"
node created: test-mhc-node-pjm2v
E0728 16:07:33.178172   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-pjm2v, got []"  "node"="test-mhc-node-pjm2v"
inframachine created: test-mhc-machine-infra-xxwf9
machine created: test-mhc-machine-lvcq2
I0728 16:07:33.212892   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:33.228328   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:33.237524   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:33.238661   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 315 lines ...
I0728 16:07:34.120857   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.122940   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.125252   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.127289   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.129961   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.139909   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:34.141217   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:34.142188   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.144245   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.146429   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.148487   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.150533   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:34.152651   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 385 lines ...
I0728 16:07:35.179944   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.182386   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.184595   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.187490   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.189210   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.190969   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:35.192649   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:35.194443   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.196696   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.197863   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.200111   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.202750   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:35.207334   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 360 lines ...
I0728 16:07:36.202752   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.205097   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.207331   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.209730   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.212102   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.213168   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:36.218015   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:36.219457   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.219934   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-lvcq2/"
I0728 16:07:36.238808   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.239398   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-lvcq2/"
node created: test-mhc-node-2dtbd
E0728 16:07:36.322517   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-2dtbd, got []"  "node"="test-mhc-node-2dtbd"
I0728 16:07:36.343990   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
inframachine created: test-mhc-machine-infra-mfjpc
machine created: test-mhc-machine-46rcx
I0728 16:07:36.367310   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.552765   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:36.561709   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 166 lines ...
I0728 16:07:37.220308   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.222860   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.226226   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.228844   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.231394   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.233556   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:37.233858   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:37.234918   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.236465   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.238235   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.239876   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.241592   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:37.243362   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 308 lines ...
I0728 16:07:38.267660   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.269179   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.270688   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.272319   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.273851   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.275397   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:38.283711   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:38.293730   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.295398   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.296890   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.305322   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.324787   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:38.335036   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
... skipping 263 lines ...
I0728 16:07:39.280357   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.283064   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.285652   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.295880   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.299378   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.308727   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
E0728 16:07:39.308776   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:39.309279   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-46rcx/"
I0728 16:07:39.323496   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.323970   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-46rcx/"
E0728 16:07:39.382982   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nmwqt, got []"  "node"="test-mhc-node-nmwqt"
node created: test-mhc-node-nmwqt
Cleaning up nodes, machines and infra machines.
I0728 16:07:39.391263   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.391818   10533 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-2kvnv/test-mhc-q54ct/test-mhc-machine-46rcx/test-mhc-node-nmwqt"
I0728 16:07:39.405181   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-q54ct" "namespace"="test-mhc-2kvnv" 
I0728 16:07:39.405731   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2kvnv/test-mhc-q54ct/test-mhc-machine-46rcx/"
Cleaning up nodes, machines and infra machines.
I0728 16:07:39.452338   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "count"=2
I0728 16:07:39.452432   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "descendants"="Worker machines: test-mhc-machine-nlbx8,test-mhc-machine-lvcq2,test-mhc-machine-46rcx" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/it_marks_unhealthy_machines_for_remediation_when_the_unhealthy_Machines_exceed_MaxUnhealthy
I0728 16:07:39.460524   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "count"=2
I0728 16:07:39.460744   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "descendants"="Worker machines: test-mhc-machine-nlbx8,test-mhc-machine-lvcq2,test-mhc-machine-46rcx" "indirect descendants count"=1
... skipping 7 lines ...
I0728 16:07:39.650277   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:39.691298   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:39.772401   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:39.933560   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:40.254689   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:40.309661   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-p5mhj" "machine"="test-mhc-machine-lvcq2" "namespace"="test-mhc-2kvnv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-2dtbd"}
E0728 16:07:40.353804   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-lvcq2\" not found" "controller"="machine" "name"="test-mhc-machine-lvcq2" "namespace"="test-mhc-2kvnv"
I0728 16:07:40.895851   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:41.354330   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:42.176994   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:42.354917   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-p5mhj" "machine"="test-mhc-machine-46rcx" "namespace"="test-mhc-2kvnv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nmwqt"}
E0728 16:07:42.427576   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-46rcx\" not found" "controller"="machine" "name"="test-mhc-machine-46rcx" "namespace"="test-mhc-2kvnv"
E0728 16:07:43.427996   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:44.428617   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-p5mhj" "machine"="test-mhc-machine-nlbx8" "namespace"="test-mhc-2kvnv" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-pjm2v"}
I0728 16:07:44.460620   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "count"=1
I0728 16:07:44.460718   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-p5mhj" "namespace"="test-mhc-2kvnv" "descendants"="Worker machines: test-mhc-machine-nlbx8" "indirect descendants count"=0
E0728 16:07:44.485797   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-nlbx8\" not found" "controller"="machine" "name"="test-mhc-machine-nlbx8" "namespace"="test-mhc-2kvnv"
I0728 16:07:44.738194   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.494866   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.499507   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:45.501040   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:45.520002   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
node created: test-mhc-node-l6p55
E0728 16:07:45.520991   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l6p55, got []"  "node"="test-mhc-node-l6p55"
E0728 16:07:45.521272   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-l6p55, got []"  "node"="test-mhc-node-l6p55"
I0728 16:07:45.527807   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
inframachine created: test-mhc-machine-infra-zdgdv
machine created: test-mhc-machine-zhqp9
I0728 16:07:45.559932   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.575799   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.578124   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.581813   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.624061   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.705864   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:45.867353   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:46.188677   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:46.501490   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:46.830004   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.514487   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.516261   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.525343   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.541901   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.548751   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.557966   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.563548   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:47.565443   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:47.584320   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
node created: test-mhc-node-9kmwq
E0728 16:07:47.657502   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9kmwq, got []"  "node"="test-mhc-node-9kmwq"
E0728 16:07:47.657502   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-9kmwq, got []"  "node"="test-mhc-node-9kmwq"
I0728 16:07:47.664841   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
inframachine created: test-mhc-machine-infra-8cf9f
machine created: test-mhc-machine-m89w9
I0728 16:07:47.685146   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.697114   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:47.698658   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:48.111445   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:48.565854   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
E0728 16:07:49.474328   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2kvnv/test-cluster-p5mhj"
I0728 16:07:49.577938   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.594258   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.611846   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.621958   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.628218   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.651640   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:49.657660   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:49.658003   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.684932   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
E0728 16:07:49.694429   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-q7x9d, got []"  "node"="test-mhc-node-q7x9d"
node created: test-mhc-node-q7x9d
Cleaning up nodes, machines and infra machines.
I0728 16:07:49.714555   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.724891   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
Cleaning up nodes, machines and infra machines.
I0728 16:07:49.766806   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-9kbqr" "namespace"="test-mhc-44j5w" "count"=2
... skipping 4 lines ...
inframachine created: test-mhc-machine-infra-f7w9r
machine created: test-mhc-machine-mvd9b
I0728 16:07:49.863605   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:49.886259   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 16:07:49.907884   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-z9xg7" "namespace"="test-mhc-44j5w" 
I0728 16:07:49.907958   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
E0728 16:07:50.658135   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:51.658718   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9kbqr" "machine"="test-mhc-machine-px2l9" "namespace"="test-mhc-44j5w" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-l6p55"}
E0728 16:07:51.708721   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-px2l9\" not found" "controller"="machine" "name"="test-mhc-machine-px2l9" "namespace"="test-mhc-44j5w"
I0728 16:07:52.709258   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9kbqr" "machine"="test-mhc-machine-zhqp9" "namespace"="test-mhc-44j5w" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-9kmwq"}
E0728 16:07:52.755339   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zhqp9\" not found" "controller"="machine" "name"="test-mhc-machine-zhqp9" "namespace"="test-mhc-44j5w"
I0728 16:07:53.755854   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-9kbqr" "machine"="test-mhc-machine-m89w9" "namespace"="test-mhc-44j5w" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-q7x9d"}
E0728 16:07:53.817822   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-m89w9\" not found" "controller"="machine" "name"="test-mhc-machine-m89w9" "namespace"="test-mhc-44j5w"
E0728 16:07:54.797137   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-44j5w/test-cluster-9kbqr"
I0728 16:07:54.827916   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
E0728 16:07:54.835086   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:07:54.835226   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
node created: test-mhc-node-z7zmv
E0728 16:07:54.865935   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-z7zmv, got []"  "node"="test-mhc-node-z7zmv"
I0728 16:07:54.873608   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
inframachine created: test-mhc-machine-infra-zwh72
I0728 16:07:54.893865   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
machine created: test-mhc-machine-zkqvq
I0728 16:07:54.904075   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
E0728 16:07:55.835528   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:56.851090   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.856257   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.866309   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.879319   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.892738   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.898283   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
E0728 16:07:56.898283   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
node created: test-mhc-node-dkzhl
E0728 16:07:56.905315   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-dkzhl, got []"  "node"="test-mhc-node-dkzhl"
I0728 16:07:56.913210   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
inframachine created: test-mhc-machine-infra-nlhqs
machine created: test-mhc-machine-l2vrr
I0728 16:07:56.933751   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.939403   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:56.949337   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.916976   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.944280   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.951456   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.962470   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.967440   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:57.975894   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
E0728 16:07:57.986812   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:07:57.987580   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
Cleaning up nodes, machines and infra machines.
I0728 16:07:58.040660   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
Cleaning up nodes, machines and infra machines.
I0728 16:07:58.051232   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:58.051815   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-sdfg2/test-mhc-vhb4h/test-mhc-machine-mvd9b/"
I0728 16:07:58.072302   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:58.073345   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-sdfg2/test-mhc-vhb4h/test-mhc-machine-mvd9b/"
I0728 16:07:58.074388   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-sdfg2/test-mhc-vhb4h/test-mhc-machine-zkqvq/"
I0728 16:07:58.094115   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-zkv9n" "namespace"="test-mhc-sdfg2" "count"=2
I0728 16:07:58.094196   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zkv9n" "namespace"="test-mhc-sdfg2" "descendants"="Worker machines: test-mhc-machine-mvd9b,test-mhc-machine-zkqvq,test-mhc-machine-l2vrr" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine_has_no_Node_ref_for_longer_than_the_NodeStartupTimeout
=== RUN   TestMachineHealthCheck_Reconcile/when_a_Machine's_Node_has_gone_away
=== RUN   TestMachineHealthCheck_Reconcile/should_react_when_a_Node_transitions_to_unhealthy
I0728 16:07:58.102258   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-zkv9n" "namespace"="test-mhc-sdfg2" "count"=2
I0728 16:07:58.102306   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-zkv9n" "namespace"="test-mhc-sdfg2" "descendants"="Worker machines: test-mhc-machine-mvd9b,test-mhc-machine-zkqvq,test-mhc-machine-l2vrr" "indirect descendants count"=1
inframachine created: test-mhc-machine-infra-kf8zf
machine created: test-mhc-machine-d8zd7
E0728 16:07:58.270613   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-vhb4h\" not found" "controller"="machinehealthcheck" "name"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2"
I0728 16:07:58.987452   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-zkv9n" "machine"="test-mhc-machine-mvd9b" "namespace"="test-mhc-sdfg2" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-z7zmv"}
E0728 16:07:59.034533   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-mvd9b\" not found" "controller"="machine" "name"="test-mhc-machine-mvd9b" "namespace"="test-mhc-sdfg2"
I0728 16:07:59.270957   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:07:59.288319   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 16:07:59.414942   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vhb4h" "namespace"="test-mhc-sdfg2" 
I0728 16:07:59.415035   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:07:59.421284   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:07:59.422339   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
... skipping 270 lines ...
I0728 16:08:00.082825   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.084628   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.091826   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.098553   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.101390   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.104542   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
E0728 16:08:00.106285   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-zkqvq\" not found" "controller"="machine" "name"="test-mhc-machine-zkqvq" "namespace"="test-mhc-sdfg2"
I0728 16:08:00.106348   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.108176   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.110018   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.111772   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.113548   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:00.115270   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
... skipping 512 lines ...
I0728 16:08:01.194356   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.196269   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.198096   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.199845   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.201650   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.203845   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
E0728 16:08:01.205661   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-l2vrr\" not found" "controller"="machine" "name"="test-mhc-machine-l2vrr" "namespace"="test-mhc-sdfg2"
I0728 16:08:01.206124   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.207973   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.209820   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.211711   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.213539   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:01.215562   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
... skipping 422 lines ...
I0728 16:08:02.212490   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.213572   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.214195   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.215900   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.217700   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.218877   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.219136   10533 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-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/"
E0728 16:08:02.219338   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:08:02.229980   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.230329   10533 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-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/"
E0728 16:08:02.294038   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nn7sf, got []"  "node"="test-mhc-node-nn7sf"
E0728 16:08:02.294393   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-nn7sf, got []"  "node"="test-mhc-node-nn7sf"
node created: test-mhc-node-nn7sf
I0728 16:08:02.305138   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.326329   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.332636   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.333919   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.334192   10533 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-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/test-mhc-node-nn7sf"
I0728 16:08:02.350548   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.351063   10533 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-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/test-mhc-node-nn7sf"
Cleaning up nodes, machines and infra machines.
I0728 16:08:02.358165   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.358604   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/"
I0728 16:08:02.377858   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.378235   10533 machinehealthcheck_controller.go:387] controllers/MachineHealthCheck "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="NodeNotFound" "target"="test-mhc-2tzng/test-mhc-ntxqz/test-mhc-machine-d8zd7/"
I0728 16:08:02.393220   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ltt57" "namespace"="test-mhc-2tzng" "descendants"="Worker machines: test-mhc-machine-d8zd7" "indirect descendants count"=1
I0728 16:08:02.399352   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-ltt57" "namespace"="test-mhc-2tzng" "descendants"="Worker machines: test-mhc-machine-d8zd7" "indirect descendants count"=1
=== RUN   TestMachineHealthCheck_Reconcile/when_in_a_MachineSet,_unhealthy_machines_should_be_deleted
I0728 16:08:02.408046   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-ntxqz" "namespace"="test-mhc-2tzng" 
I0728 16:08:02.526214   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" "creating"=1 "need"=1
I0728 16:08:02.526273   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:02.547167   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"mhc-ms-2lr6m-vtljs\"" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:02.618646   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:02.670686   10533 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinehealthcheck" "source"={}
I0728 16:08:02.791198   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
E0728 16:08:03.113988   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-sdfg2/test-cluster-zkv9n"
E0728 16:08:03.220983   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:08:03.791403   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:04.223218   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-ltt57" "machine"="test-mhc-machine-d8zd7" "namespace"="test-mhc-2tzng" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-nn7sf"}
E0728 16:08:04.274020   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-d8zd7\" not found" "controller"="machine" "name"="test-mhc-machine-d8zd7" "namespace"="test-mhc-2tzng"
I0728 16:08:04.792516   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.283176   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.283348   10533 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.289466   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.289761   10533 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.301103   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
... skipping 7 lines ...
I0728 16:08:05.344601   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.344656   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:05.793586   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:06.316914   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:06.316961   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.000707   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.001141   10533 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-4x4xx/test-mhc-xbcm2/mhc-ms-2lr6m-vtljs/"
I0728 16:08:07.010714   10533 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.014218   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.014273   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.016043   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.016375   10533 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-4x4xx/test-mhc-xbcm2/mhc-ms-2lr6m-vtljs/"
I0728 16:08:07.024878   10533 machineset_controller.go:139] controllers/MachineSet "msg"="Reconciliation is paused for this object" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.025130   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.025454   10533 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-4x4xx/test-mhc-xbcm2/mhc-ms-2lr6m-vtljs/"
I0728 16:08:07.029493   10533 cluster_controller.go:223] controllers/Cluster "msg"="Cluster still has children - deleting them first" "cluster"="test-cluster-pv7w4" "namespace"="test-mhc-4x4xx" "count"=1
I0728 16:08:07.029558   10533 cluster_controller.go:241] controllers/Cluster "msg"="Deleting child" "cluster"="test-cluster-pv7w4" "namespace"="test-mhc-4x4xx" "gvk"="cluster.x-k8s.io/v1alpha3, Kind=MachineSet" "name"="mhc-ms-2lr6m"
I0728 16:08:07.033789   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.033835   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" 
I0728 16:08:07.033914   10533 machineset_controller.go:237] controllers/MachineSet "msg"="Deleting unhealthy machine" "machineset"="mhc-ms-2lr6m" "namespace"="test-mhc-4x4xx" "machine"="mhc-ms-2lr6m-vtljs"
I0728 16:08:07.034701   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-xbcm2" "namespace"="test-mhc-4x4xx" 
... skipping 32 lines ...
I0728 16:08:07.284741   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.286572   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.287767   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.288350   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.290250   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.290805   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-pv7w4" "machine"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx" "cause"="cluster is being deleted" "node"=null
E0728 16:08:07.348073   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qmm9k, got []"  "node"="test-mhc-node-qmm9k"
node created: test-mhc-node-qmm9k
E0728 16:08:07.348313   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qmm9k, got []"  "node"="test-mhc-node-qmm9k"
E0728 16:08:07.348696   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-qmm9k, got []"  "node"="test-mhc-node-qmm9k"
E0728 16:08:07.353172   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"mhc-ms-2lr6m-vtljs\" not found" "controller"="machine" "name"="mhc-ms-2lr6m-vtljs" "namespace"="test-mhc-4x4xx"
I0728 16:08:07.390532   10533 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-529dk" "target"="test-mhc-fvk74/test-mhc-vtv2x/test-mhc-machine-529dk/"
I0728 16:08:07.407633   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
E0728 16:08:07.418685   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-2tzng/test-cluster-ltt57"
I0728 16:08:07.432400   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.437424   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.439566   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.449789   10533 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-529dk" "target"="test-mhc-fvk74/test-mhc-vtv2x/test-mhc-machine-529dk/test-mhc-node-qmm9k"
I0728 16:08:07.466824   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
Cleaning up nodes, machines and infra machines.
I0728 16:08:07.474793   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.485247   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.487844   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-vtv2x" "namespace"="test-mhc-fvk74" 
I0728 16:08:07.495038   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-6vjnw" "namespace"="test-mhc-fvk74" "descendants"="Worker machines: test-mhc-machine-529dk" "indirect descendants count"=1
... skipping 327 lines ...
I0728 16:08:08.395311   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.397072   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.399021   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.401624   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.404392   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.406493   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
E0728 16:08:08.406861   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-529dk\" not found" "controller"="machine" "name"="test-mhc-machine-529dk" "namespace"="test-mhc-fvk74"
I0728 16:08:08.408438   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.410396   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.412234   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.422863   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.425061   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:08.427034   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
... skipping 445 lines ...
I0728 16:08:09.396528   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.398518   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.400760   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.402646   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.404694   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.406573   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
E0728 16:08:09.407181   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
I0728 16:08:09.408555   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.410377   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.412207   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.414180   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.416328   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:09.418180   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
... skipping 492 lines ...
I0728 16:08:10.412284   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.414303   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.415244   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.416262   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.418153   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.419914   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
E0728 16:08:10.420067   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
I0728 16:08:10.424050   10533 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-ml7c7" "target"="test-mhc-c44xl/test-mhc-t42ct/test-mhc-machine-ml7c7/"
I0728 16:08:10.479960   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
node created: test-mhc-node-xh9x8
E0728 16:08:10.484149   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xh9x8, got []"  "node"="test-mhc-node-xh9x8"
E0728 16:08:10.484151   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xh9x8, got []"  "node"="test-mhc-node-xh9x8"
E0728 16:08:10.484374   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node test-mhc-node-xh9x8, got []"  "node"="test-mhc-node-xh9x8"
I0728 16:08:10.490389   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.509345   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.514336   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.518242   10533 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-ml7c7" "target"="test-mhc-c44xl/test-mhc-t42ct/test-mhc-machine-ml7c7/test-mhc-node-xh9x8"
I0728 16:08:10.536731   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.548966   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.569714   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.576979   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
Cleaning up nodes, machines and infra machines.
I0728 16:08:10.588304   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
I0728 16:08:10.592895   10533 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-ml7c7" "target"="test-mhc-c44xl/test-mhc-t42ct/test-mhc-machine-ml7c7/"
I0728 16:08:10.605379   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jgzts" "namespace"="test-mhc-c44xl" "descendants"="Worker machines: test-mhc-machine-ml7c7" "indirect descendants count"=1
I0728 16:08:10.611594   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster-jgzts" "namespace"="test-mhc-c44xl" "descendants"="Worker machines: test-mhc-machine-ml7c7" "indirect descendants count"=1
E0728 16:08:10.611591   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinehealthchecks.cluster.x-k8s.io \"test-mhc-t42ct\" not found" "controller"="machinehealthcheck" "name"="test-mhc-t42ct" "namespace"="test-mhc-c44xl"
--- PASS: TestMachineHealthCheck_Reconcile (40.82s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_no_existing_labels_exist (0.15s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_the_label_has_the_wrong_value (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_the_correct_cluster-name_label_when_other_labels_are_present (0.03s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_no_existing_ones_exist (1.04s)
    --- PASS: TestMachineHealthCheck_Reconcile/it_should_ensure_an_owner_reference_is_present_when_modifying_existing_ones (0.34s)
... skipping 10 lines ...
    --- SKIP: TestMachineHealthCheck_Reconcile/when_a_machine_is_paused (0.00s)
        machinehealthcheck_controller_test.go:933: skipping until made stable
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_to_unhealthy,_new_Remediation_Request_should_be_created (0.46s)
    --- PASS: TestMachineHealthCheck_Reconcile/When_remediationTemplate_is_set_and_node_transitions_back_to_healthy,_new_Remediation_Request_should_be_deleted (3.12s)
=== RUN   TestClusterToMachineHealthCheck
=== RUN   TestClusterToMachineHealthCheck/when_the_object_passed_isn't_a_cluster
E0728 16:08:10.621153   10533 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
E0728 16:08:10.622828   10533 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
E0728 16:08:10.624776   10533 machinehealthcheck_controller.go:474]  "msg"="expected a Node" "error"="incorrect type"  "type"="handler.MapObject"
=== RUN   TestNodeToMachineHealthCheck/when_no_Machine_exists_for_the_Node
E0728 16:08:10.625077   10533 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
E0728 16:08:10.626175   10533 machinehealthcheck_controller.go:480]  "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node node1, got [machine1 machine2]"  "node"="node1"
=== RUN   TestNodeToMachineHealthCheck/when_no_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_two_MachineHealthChecks_exist_for_the_Node_in_the_Machine's_namespace
=== RUN   TestNodeToMachineHealthCheck/when_a_MachineHealthCheck_exists_for_the_Node,_but_not_in_the_Machine's_cluster
--- PASS: TestNodeToMachineHealthCheck (0.01s)
    --- PASS: TestNodeToMachineHealthCheck/when_the_object_passed_isn't_a_Node (0.00s)
... skipping 31 lines ...
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_nil (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_not_an_int_or_percentage (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_an_int (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_40%_(of_5) (0.00s)
    --- PASS: TestGetMaxUnhealthy/when_maxUnhealthy_is_a_60%_(of_7) (0.00s)
=== RUN   TestPatchTargets
I0728 16:08:10.632306   10533 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine1/"
I0728 16:08:10.633532   10533 machinehealthcheck_controller.go:387]  "msg"="Target has failed health check, marking for remediation"  "message"="" "reason"="" "target"="default/mhc/machine2/"
E0728 16:08:10.634809   10533 machinehealthcheck_controller.go:320]  "msg"="failed to patch healthy machine status for machine" "error"="machines.cluster.x-k8s.io \"machine1\" not found"  "machine"="machine1"
--- PASS: TestPatchTargets (0.00s)
=== RUN   TestGetTargetsFromMHC
=== RUN   TestGetTargetsFromMHC/with_no_matching_machines
=== RUN   TestGetTargetsFromMHC/when_a_machine's_node_is_missing
=== RUN   TestGetTargetsFromMHC/when_a_machine's_labels_do_not_match_the_selector
=== RUN   TestGetTargetsFromMHC/with_multiple_machines,_should_match_correct_nodes
... skipping 26 lines ...
--- PASS: TestMachineSetOwnerReference (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_add_cluster_owner_reference_to_machine_set (0.00s)
    --- PASS: TestMachineSetOwnerReference/should_not_add_cluster_owner_reference_if_machine_is_owned_by_a_machine_deployment (0.00s)
=== RUN   TestMachineSetReconcile
=== RUN   TestMachineSetReconcile/ignore_machine_sets_marked_for_deletion
=== RUN   TestMachineSetReconcile/records_event_if_reconcile_fails
E0728 16:08:10.641355   10533 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
E0728 16:08:10.642477   10533 machineset_controller.go:569]  "msg"="Unable to convert selector" "error"="\"bad-operator\" is not a valid pod selector operator" "machine"="match" "machineset"="" "namespace"="" 
--- PASS: TestHasMatchingLabels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_and_machine_do_not_have_matching_labels (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_empty_selector (0.00s)
    --- PASS: TestHasMatchingLabels/machine_set_has_bad_selector (0.00s)
=== RUN   TestMachineToDelete
... skipping 73 lines ...
I0728 16:08:10.951314   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "creating"=1 "need"=3
I0728 16:08:10.951361   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" 
I0728 16:08:10.961373   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-6657c7fddb-7s6sj\"" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" 
I0728 16:08:11.025075   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=1
I0728 16:08:11.025127   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
I0728 16:08:11.036521   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-cdfc6fd6c-97t2d\"" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
E0728 16:08:11.123686   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.123687   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.123740   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227454   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227525   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227454   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227561   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227729   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.227808   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-97t2d-xfb4w, got []"  "node"="md-nb6d9-cdfc6fd6c-97t2d-xfb4w"
E0728 16:08:11.253993   10533 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node md-nb6d9-cdfc6fd6c-97t2d-xfb4w for machine md-test/md-nb6d9-cdfc6fd6c-97t2d: the cache is not started, can not read objects" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
I0728 16:08:11.283712   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=2
I0728 16:08:11.283844   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:11.290713   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "machine"="md-nb6d9-6657c7fddb-bsrtl"
I0728 16:08:11.312991   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=2
I0728 16:08:11.313039   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
I0728 16:08:11.323131   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-cdfc6fd6c-r7jqt\"" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
E0728 16:08:11.356318   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.356528   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.356560   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
I0728 16:08:11.420625   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster-jgzts" "machine"="test-mhc-machine-ml7c7" "namespace"="test-mhc-c44xl" "cause"="cluster is being deleted" "node"={"name":"test-mhc-node-xh9x8"}
E0728 16:08:11.470054   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.470096   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.470063   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.470121   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.470192   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.470236   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-r7jqt-4m2nj, got []"  "node"="md-nb6d9-cdfc6fd6c-r7jqt-4m2nj"
E0728 16:08:11.471144   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"test-mhc-machine-ml7c7\" not found" "controller"="machine" "name"="test-mhc-machine-ml7c7" "namespace"="test-mhc-c44xl"
I0728 16:08:11.512810   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=1
I0728 16:08:11.512918   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:11.517091   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "machine"="md-nb6d9-6657c7fddb-ndbrp"
I0728 16:08:11.542585   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "creating"=1 "need"=3
I0728 16:08:11.542629   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
I0728 16:08:11.552589   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-cdfc6fd6c-gmtw9\"" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" 
I0728 16:08:11.612220   10533 machinehealthcheck_controller.go:109] controllers/MachineHealthCheck "msg"="Reconciling" "machinehealthcheck"="test-mhc-t42ct" "namespace"="test-mhc-c44xl" 
E0728 16:08:11.626564   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.626731   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.626731   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730432   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730471   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730721   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730741   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730820   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
E0728 16:08:11.730870   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-cdfc6fd6c-gmtw9-kl9gb, got []"  "node"="md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"
I0728 16:08:11.772783   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "deleting"=1 "need"=0
I0728 16:08:11.772830   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:11.776786   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-6657c7fddb" "namespace"="md-test" "machine"="md-nb6d9-6657c7fddb-7s6sj"
I0728 16:08:12.033022   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=1
I0728 16:08:12.033103   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(1) \u003e currentMachineCount(0) )" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
I0728 16:08:12.049068   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-74d45c49c5-h4k2m\"" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
E0728 16:08:12.057940   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-4x4xx/test-cluster-pv7w4"
E0728 16:08:12.130924   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
E0728 16:08:12.130985   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
E0728 16:08:12.234757   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
E0728 16:08:12.234815   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
E0728 16:08:12.235119   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
E0728 16:08:12.235174   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-h4k2m-75rfh, got []"  "node"="md-nb6d9-74d45c49c5-h4k2m-75rfh"
I0728 16:08:12.273780   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=2
I0728 16:08:12.273830   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:12.284259   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "machine"="md-nb6d9-cdfc6fd6c-r7jqt"
I0728 16:08:12.341699   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=2
I0728 16:08:12.341754   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
I0728 16:08:12.357379   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-74d45c49c5-7k54m\"" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
E0728 16:08:12.484787   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-7k54m-v586k, got []"  "node"="md-nb6d9-74d45c49c5-7k54m-v586k"
E0728 16:08:12.485290   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-7k54m-v586k, got []"  "node"="md-nb6d9-74d45c49c5-7k54m-v586k"
E0728 16:08:12.526672   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-fvk74/test-cluster-6vjnw"
I0728 16:08:12.564413   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:12.564463   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:12.584379   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:12.584424   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
E0728 16:08:12.589040   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-7k54m-v586k, got []"  "node"="md-nb6d9-74d45c49c5-7k54m-v586k"
E0728 16:08:12.589134   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-7k54m-v586k, got []"  "node"="md-nb6d9-74d45c49c5-7k54m-v586k"
E0728 16:08:12.634621   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-cdfc6fd6c-97t2d\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-cdfc6fd6c-97t2d" "namespace"="md-test"
I0728 16:08:12.637830   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=1
I0728 16:08:12.637885   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:12.641784   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "machine"="md-nb6d9-cdfc6fd6c-gmtw9"
I0728 16:08:12.658472   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" "creating"=1 "need"=3
I0728 16:08:12.658519   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(3) \u003e currentMachineCount(2) )" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
I0728 16:08:12.669890   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"md-nb6d9-74d45c49c5-xmt6f\"" "machineset"="md-nb6d9-74d45c49c5" "namespace"="md-test" 
E0728 16:08:12.738098   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-xmt6f-rn76t, got []"  "node"="md-nb6d9-74d45c49c5-xmt6f-rn76t"
E0728 16:08:12.740689   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-xmt6f-rn76t, got []"  "node"="md-nb6d9-74d45c49c5-xmt6f-rn76t"
E0728 16:08:12.740761   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node md-nb6d9-74d45c49c5-xmt6f-rn76t, got []"  "node"="md-nb6d9-74d45c49c5-xmt6f-rn76t"
I0728 16:08:12.769170   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-nb6d9-74d45c49c5,md-nb6d9-cdfc6fd6c;Worker machines: md-nb6d9-74d45c49c5-xmt6f,md-nb6d9-6657c7fddb-sgmtt,md-nb6d9-6657c7fddb-d6qcb,md-nb6d9-74d45c49c5-7k54m,md-nb6d9-cdfc6fd6c-gmtw9,md-nb6d9-74d45c49c5-h4k2m,md-nb6d9-cdfc6fd6c-97t2d" "indirect descendants count"=9
E0728 16:08:12.773621   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machinedeployments.cluster.x-k8s.io \"md-nb6d9\" not found" "controller"="machinedeployment" "name"="md-nb6d9" "namespace"="md-test"
I0728 16:08:12.774774   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-nb6d9-74d45c49c5,md-nb6d9-cdfc6fd6c;Worker machines: md-nb6d9-6657c7fddb-sgmtt,md-nb6d9-6657c7fddb-d6qcb,md-nb6d9-74d45c49c5-7k54m,md-nb6d9-cdfc6fd6c-gmtw9,md-nb6d9-74d45c49c5-h4k2m,md-nb6d9-cdfc6fd6c-97t2d,md-nb6d9-74d45c49c5-xmt6f" "indirect descendants count"=9
•I0728 16:08:12.777589   10533 machineset_controller.go:388] controllers/MachineSet "msg"="Too many replicas" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "deleting"=1 "need"=0
I0728 16:08:12.777638   10533 machineset_controller.go:394] controllers/MachineSet "msg"="Found delete policy" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "delete-policy"="Random"
I0728 16:08:12.781887   10533 machineset_controller.go:405] controllers/MachineSet "msg"="Deleted machine" "machineset"="md-nb6d9-cdfc6fd6c" "namespace"="md-test" "machine"="md-nb6d9-cdfc6fd6c-97t2d"
I0728 16:08:12.914222   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-vgxwf" "namespace"="ms-test" "creating"=2 "need"=2
I0728 16:08:12.914290   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-vgxwf" "namespace"="ms-test" 
I0728 16:08:12.928045   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 2 with name \"ms-vgxwf-bp8bb\"" "machineset"="ms-vgxwf" "namespace"="ms-test" 
I0728 16:08:12.928134   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 2 of 2, ( spec.replicas(2) \u003e currentMachineCount(0) )" "machineset"="ms-vgxwf" "namespace"="ms-test" 
I0728 16:08:12.946953   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 2 of 2 with name \"ms-vgxwf-gmcsz\"" "machineset"="ms-vgxwf" "namespace"="ms-test" 
I0728 16:08:13.098896   10533 machineset_controller.go:316] controllers/MachineSet "msg"="Too few replicas" "machineset"="ms-vgxwf" "namespace"="ms-test" "creating"=1 "need"=2
I0728 16:08:13.098948   10533 machineset_controller.go:324] controllers/MachineSet "msg"="Creating machine 1 of 1, ( spec.replicas(2) \u003e currentMachineCount(1) )" "machineset"="ms-vgxwf" "namespace"="ms-test" 
I0728 16:08:13.114164   10533 machineset_controller.go:378] controllers/MachineSet "msg"="Created machine 1 of 1 with name \"ms-vgxwf-fsnn5\"" "machineset"="ms-vgxwf" "namespace"="ms-test" 
E0728 16:08:13.209488   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-fsnn5-pwvrr, got []"  "node"="ms-vgxwf-fsnn5-pwvrr"
E0728 16:08:13.212154   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-fsnn5-pwvrr, got []"  "node"="ms-vgxwf-fsnn5-pwvrr"
E0728 16:08:13.212198   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-fsnn5-pwvrr, got []"  "node"="ms-vgxwf-fsnn5-pwvrr"
E0728 16:08:13.235759   10533 machineset_controller.go:625] controllers/MachineSet "msg"="Unable to retrieve Node status" "error"="error retrieving node ms-vgxwf-fsnn5-pwvrr for machine ms-test/ms-vgxwf-fsnn5: the cache is not started, can not read objects" "machineset"="ms-vgxwf" "namespace"="ms-test" 
E0728 16:08:13.241982   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-gmcsz-k2w4q, got []"  "node"="ms-vgxwf-gmcsz-k2w4q"
E0728 16:08:13.244968   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-gmcsz-k2w4q, got []"  "node"="ms-vgxwf-gmcsz-k2w4q"
E0728 16:08:13.245012   10533 machinehealthcheck_controller.go:480] controllers/MachineHealthCheck "msg"="Unable to retrieve machine from node" "error"="expecting one machine for node ms-vgxwf-gmcsz-k2w4q, got []"  "node"="ms-vgxwf-gmcsz-k2w4q"
I0728 16:08:13.365720   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vgxwf-fsnn5,ms-vgxwf-gmcsz" "indirect descendants count"=2
•I0728 16:08:13.368527   10533 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"
I0728 16:08:13.369060   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vgxwf-fsnn5,ms-vgxwf-gmcsz" "indirect descendants count"=2
I0728 16:08:13.369634   10533 machine_controller_phases.go:219]  "msg"="Bootstrap provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0728 16:08:13.369695   10533 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"
I0728 16:08:13.370562   10533 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
... skipping 15 lines ...
I0728 16:08:13.380184   10533 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"
•I0728 16:08:13.381911   10533 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"
I0728 16:08:13.382836   10533 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"
I0728 16:08:13.383576   10533 machine_controller_phases.go:278]  "msg"="Infrastructure provider is not ready, requeuing" "machine"="machine-test" "namespace"="default" 
I0728 16:08:13.383615   10533 machine_controller_noderef.go:45]  "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="machine-test" "namespace"="default" 
•I0728 16:08:13.384324   10533 machine_controller.go:327]  "msg"="Draining node" "cluster"="test-cluster" "machine"="machine-test" "namespace"="default" "node"="machine-test-node"
E0728 16:08:13.385946   10533 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" 
••E0728 16:08:13.508785   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test1-p5xnl\" not found" "controller"="cluster" "name"="test1-p5xnl" "namespace"="default"
I0728 16:08:13.635199   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-nb6d9-cdfc6fd6c-gmtw9" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"}
E0728 16:08:13.679643   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
•I0728 16:08:14.633815   10533 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-s6hkr" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0728 16:08:14.709339   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
I0728 16:08:14.754064   10533 conversion.go:64] controllers/Cluster "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "cluster"="test2-s6hkr" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
E0728 16:08:14.758728   10533 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-s6hkr" "namespace"="default"
I0728 16:08:15.713848   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:15.713892   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:15.717462   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:15.717499   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:15.717977   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-nb6d9-cdfc6fd6c-97t2d" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-nb6d9-cdfc6fd6c-97t2d-xfb4w"}
E0728 16:08:15.771696   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
I0728 16:08:15.776240   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-nb6d9-cdfc6fd6c-gmtw9" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-nb6d9-cdfc6fd6c-gmtw9-kl9gb"}
E0728 16:08:15.808321   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-nb6d9-cdfc6fd6c-gmtw9\" not found" "controller"="machine" "name"="md-nb6d9-cdfc6fd6c-gmtw9" "namespace"="md-test"
•E0728 16:08:16.783492   10533 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="test-mhc-c44xl/test-cluster-jgzts"
E0728 16:08:16.796300   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="clusters.cluster.x-k8s.io \"test3-49pqt\" not found" "controller"="cluster" "name"="test3-49pqt" "namespace"="default"
E0728 16:08:16.816259   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
E0728 16:08:17.797270   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
E0728 16:08:17.821711   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
I0728 16:08:18.807943   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-nb6d9-cdfc6fd6c,md-nb6d9-74d45c49c5;Worker machines: md-nb6d9-cdfc6fd6c-97t2d,md-nb6d9-74d45c49c5-xmt6f,md-nb6d9-6657c7fddb-sgmtt,md-nb6d9-6657c7fddb-d6qcb,md-nb6d9-74d45c49c5-7k54m,md-nb6d9-74d45c49c5-h4k2m" "indirect descendants count"=8
E0728 16:08:18.808600   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
I0728 16:08:18.822219   10533 machine_controller.go:305] controllers/Machine "msg"="Deleting Kubernetes Node associated with Machine is not allowed" "cluster"="test-cluster" "machine"="md-nb6d9-cdfc6fd6c-97t2d" "namespace"="md-test" "cause"="cluster is being deleted" "node"={"name":"md-nb6d9-cdfc6fd6c-97t2d-xfb4w"}
E0728 16:08:18.847950   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="machines.cluster.x-k8s.io \"md-nb6d9-cdfc6fd6c-97t2d\" not found" "controller"="machine" "name"="md-nb6d9-cdfc6fd6c-97t2d" "namespace"="md-test"
•I0728 16:08:19.809198   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vgxwf-fsnn5,ms-vgxwf-gmcsz" "indirect descendants count"=2
E0728 16:08:19.813990   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
I0728 16:08:19.949492   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:19.949555   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:19.955844   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:19.955891   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
E0728 16:08:19.962669   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
E0728 16:08:20.814849   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
E0728 16:08:20.967549   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
E0728 16:08:21.824511   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
•E0728 16:08:21.968035   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-wr9mx\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-wr9mx" "namespace"="test-mhc-lxrms"
E0728 16:08:22.825285   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
E0728 16:08:22.994149   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
E0728 16:08:23.826149   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
E0728 16:08:23.994522   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get cluster \"test-cluster-988jc\" for machine \"test-mhc-machine-2rkgp\" in namespace \"test-mhc-lxrms\": Cluster.cluster.x-k8s.io \"test-cluster-988jc\" not found" "controller"="machine" "name"="test-mhc-machine-2rkgp" "namespace"="test-mhc-lxrms"
E0728 16:08:24.837638   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
I0728 16:08:24.999045   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:24.999086   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:25.002795   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:25.002840   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
E0728 16:08:25.006899   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
I0728 16:08:25.838370   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="md-test" "descendants"="Machine sets: md-nb6d9-74d45c49c5,md-nb6d9-cdfc6fd6c;Worker machines: md-nb6d9-6657c7fddb-sgmtt,md-nb6d9-6657c7fddb-d6qcb,md-nb6d9-74d45c49c5-7k54m,md-nb6d9-74d45c49c5-xmt6f,md-nb6d9-74d45c49c5-h4k2m" "indirect descendants count"=7
E0728 16:08:25.838864   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
E0728 16:08:26.019281   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
I0728 16:08:26.839550   10533 cluster_controller.go:256] controllers/Cluster "msg"="Cluster still has descendants - need to requeue" "cluster"="test-cluster" "namespace"="ms-test" "descendants"="Worker machines: ms-vgxwf-fsnn5,ms-vgxwf-gmcsz" "indirect descendants count"=2
E0728 16:08:26.840515   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
E0728 16:08:27.035054   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
E0728 16:08:27.841356   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
I0728 16:08:28.039836   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:28.039883   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-sgmtt" "namespace"="md-test" 
I0728 16:08:28.043496   10533 machine_controller_phases.go:278] controllers/Machine "msg"="Infrastructure provider is not ready, requeuing" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
I0728 16:08:28.043534   10533 machine_controller_noderef.go:45] controllers/Machine "msg"="Cannot reconcile Machine's Node, no valid ProviderID yet" "machine"="md-nb6d9-6657c7fddb-d6qcb" "namespace"="md-test" 
E0728 16:08:28.047347   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-h4k2m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-h4k2m" "namespace"="md-test"
E0728 16:08:28.842137   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test-too\" for Cluster default/test2-s6hkr: failed to retrieve  external object \"default\"/\"test-too\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test2-s6hkr" "namespace"="default"
I0728 16:08:29.062051   10533 conversion.go:64] controllers/Machine "msg"="Cannot retrieve CRD with metadata only client, falling back to slower listing" "machine"="test6-d4bb6" "namespace"="default" "err"="you requested PartialObjectMetadata, but the requested object is a list (*apiextensions.CustomResourceDefinitionList)"
I0728 16:08:29.173032   10533 machine_controller_noderef.go:86] controllers/Machine "msg"="Set Machine's NodeRef" "machine"="test6-d4bb6" "namespace"="default" "noderef"="id-node-1"
E0728 16:08:29.200043   10533 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-d4bb6" "namespace"="default"
E0728 16:08:29.842997   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"
E0728 16:08:30.205649   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="no matching Node for Machine \"md-nb6d9-74d45c49c5-7k54m\" in namespace \"md-test\": cannot find node with matching ProviderID" "controller"="machine" "name"="md-nb6d9-74d45c49c5-7k54m" "namespace"="md-test"
E0728 16:08:30.847555   10533 controller.go:257] controller-runtime/controller "msg"="Reconciler error" "error"="failed to get  \"test\" for Cluster default/test4-h7rsb: failed to retrieve  external object \"default\"/\"test\": Object 'Kind' is missing in 'unstructured object has no kind'" "controller"="cluster" "name"="test4-h7rsb" "namespace"="default"

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


Ran 16 of 16 Specs in 20.285 seconds
SUCCESS! -- 16 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (20.28s)
PASS
Tearing down test suite
I0728 16:08:30.928604   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0728 16:08:30.928622   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinehealthcheck" 
I0728 16:08:30.928642   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machineset" 
I0728 16:08:30.928657   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machine" 
I0728 16:08:30.928672   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0728 16:08:30.928684   10533 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
I0728 16:08:30.928733   10533 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0728 16:08:30.928831   10533 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="inotify instance already closed"  
E0728 16:08:30.929165   10533 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-591889617/tls.crt: no such file or directory"  
E0728 16:08:30.955361   10533 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:42057/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1282&timeout=10s&timeoutSeconds=522&watch=true: dial tcp 127.0.0.1:42057: connect: connection refused
E0728 16:08:30.955464   10533 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:42057/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1282&timeout=10s&timeoutSeconds=519&watch=true: dial tcp 127.0.0.1:42057: connect: connection refused
E0728 16:08:30.955464   10533 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:42057/api/v1/nodes?allowWatchBookmarks=true&resourceVersion=1282&timeout=10s&timeoutSeconds=540&watch=true: dial tcp 127.0.0.1:42057: connect: connection refused
ok  	sigs.k8s.io/cluster-api/controllers	80.887s
=== RUN   TestGetResourceFound
--- PASS: TestGetResourceFound (0.00s)
=== RUN   TestGetResourceNotFound
--- PASS: TestGetResourceNotFound (0.00s)
=== RUN   TestCloneTemplateResourceNotFound
... skipping 260 lines ...
I0728 16:07:24.369720   10862 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
I0728 16:07:24.369920   10862 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=40629
I0728 16:07:24.393334   10862 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}}}
I0728 16:07:24.493853   10862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="cluster" 
I0728 16:07:24.493908   10862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="cluster" "worker count"=1
•I0728 16:07:24.953051   10862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="cluster" 
E0728 16:07:26.980110   10862 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="timed out waiting for the condition"  "cluster"="cluster-cache-test-t7lwm/test-cluster"
•E0728 16:07:27.432063   10862 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="the server could not find the requested resource"  "cluster"="cluster-cache-test-6b9b5/test-cluster"
•E0728 16:07:28.007309   10862 cluster_cache.go:366]  "msg"="Error health checking cluster" "error"="Get http://127.0.0.1:39937/?timeout=50ms: dial tcp 127.0.0.1:39937: connect: connection refused"  "cluster"="cluster-cache-test-r954c/test-cluster"
•I0728 16:07:28.233870   10862 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":{}}}
I0728 16:07:28.434294   10862 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="machinedeployment" 
I0728 16:07:28.434355   10862 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="machinedeployment" "worker count"=1
I0728 16:07:28.434412   10862 controller.go:132] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinedeployment" "source"={}
•I0728 16:07:28.970344   10862 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="machinedeployment" 
I0728 16:07:28.970508   10862 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  
E0728 16:07:29.018998   10862 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:43153/apis/cluster.x-k8s.io/v1alpha3/clusters?allowWatchBookmarks=true&resourceVersion=146&timeout=10s&timeoutSeconds=478&watch=true: dial tcp 127.0.0.1:43153: connect: connection refused


Ran 5 of 5 Specs in 17.507 seconds
SUCCESS! -- 5 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestGinkgoSuite (17.51s)
PASS
ok  	sigs.k8s.io/cluster-api/controllers/remote	17.694s
?   	sigs.k8s.io/cluster-api/controllers/remote/fake	[no test files]
?   	sigs.k8s.io/cluster-api/controlplane/kubeadm	[no test files]
=== RUN   TestKubeadmControlPlaneDefault
... skipping 208 lines ...
=== RUN   TestReconcileNoClusterOwnerRef
I0728 16:07:38.090236   11599 controller.go:130]  "msg"="Cluster Controller has not yet set OwnerRef" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoClusterOwnerRef (0.00s)
=== RUN   TestReconcileNoKCP
--- PASS: TestReconcileNoKCP (0.00s)
=== RUN   TestReconcileNoCluster
E0728 16:07:38.091517   11599 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="clusters.cluster.x-k8s.io \"foo\" not found" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcileNoCluster (0.00s)
=== RUN   TestReconcilePaused
I0728 16:07:38.092179   11599 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
I0728 16:07:38.092332   11599 controller.go:136]  "msg"="Reconciliation is paused for this object" "cluster"="foo" "kubeadmControlPlane"="foo" "namespace"="test" 
--- PASS: TestReconcilePaused (0.00s)
=== RUN   TestReconcileClusterNoEndpoints
... skipping 192 lines ...
    --- PASS: TestSelectMachineForScaleDown/when_there_is_an_up_to_date_machine_with_delete_annotation,_while_there_are_any_outdated_machines_without_annotatio_that_still_exist,_it_returns_oldest_marked_machine_first (0.00s)
=== RUN   TestPreflightChecks
=== RUN   TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass
=== RUN   TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue
I0728 16:07:56.603572   11599 scale.go:173]  "msg"="Waiting for machines to be deleted" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "Machines"=""
=== RUN   TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue
I0728 16:07:56.603743   11599 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="" "kubeadmControlPlane"="" "namespace"="" "failures"="machine  reports APIServerPodHealthy condition is false (Error, )"
=== RUN   TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass
--- PASS: TestPreflightChecks (0.00s)
    --- PASS: TestPreflightChecks/control_plane_without_machines_(not_initialized)_should_pass (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_a_deleting_machine_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_unhealthy_machine_condition_should_requeue (0.00s)
    --- PASS: TestPreflightChecks/control_plane_with_an_healthy_machine_and_an_healthy_kcp_condition_should_pass (0.00s)
... skipping 18 lines ...
=== RUN   TestAPIs
Running Suite: Controller Suite
===============================
Random Seed: 1627488443
Will run 1 of 1 specs

E0728 16:07:56.629493   11599 controller.go:126]  "msg"="Failed to retrieve owner Cluster from the API Server" "error"="Cluster.cluster.x-k8s.io \"kcp-foo-qy16c6\" not found" "kubeadmControlPlane"="kcp-foo-qy16c6" "namespace"="test" 
•

Ran 1 of 1 Specs in 0.022 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (0.02s)
=== RUN   TestKubeadmControlPlaneReconciler_upgradeControlPlane
I0728 16:07:56.630636   11599 controller.go:246]  "msg"="Reconcile KubeadmControlPlane" "cluster"="kcp-foo-ag9knw" "kubeadmControlPlane"="kcp-foo-ag9knw" "namespace"="test" 
I0728 16:07:58.722794   11599 controller.go:331]  "msg"="Rolling out Control Plane machines" "cluster"="kcp-foo-ag9knw" "kubeadmControlPlane"="kcp-foo-ag9knw" "namespace"="test" "needRollout"=["kcp-foo-ag9knw-gc9cs"]
I0728 16:07:58.722943   11599 scale.go:212]  "msg"="Waiting for control plane to pass preflight checks" "cluster"="kcp-foo-ag9knw" "kubeadmControlPlane"="kcp-foo-ag9knw" "namespace"="test" "failures"="[machine kcp-foo-ag9knw-5clpx does not have APIServerPodHealthy condition, machine kcp-foo-ag9knw-5clpx does not have ControllerManagerPodHealthy condition, machine kcp-foo-ag9knw-5clpx does not have SchedulerPodHealthy condition, machine kcp-foo-ag9knw-5clpx does not have EtcdPodHealthy condition, machine kcp-foo-ag9knw-5clpx does not have EtcdMemberHealthy condition]"
--- PASS: TestKubeadmControlPlaneReconciler_upgradeControlPlane (2.09s)
... skipping 60 lines ...
==================================
Random Seed: 1627488442
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: 1627488442
Will run 7 of 7 specs

•••••••
Ran 7 of 7 Specs in 0.001 seconds
SUCCESS! -- 7 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestMachineCollection (0.00s)
=== RUN   TestUpdateEtcdConditions
=== RUN   TestUpdateEtcdConditions/if_list_nodes_return_an_error_should_report_all_the_conditions_Unknown
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_be_ignored_if_there_are_provisioning_machines
=== RUN   TestUpdateEtcdConditions/node_without_machine_should_report_a_problem_at_KCP_level_if_there_are_no_provisioning_machines
=== RUN   TestUpdateEtcdConditions/failure_creating_the_etcd_client_should_report_unknown_condition
... skipping 297 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
E0728 16:07:39.933477   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:07:48.256585   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:07:57.242578   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:08:08.373447   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:08:24.846673   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:08:37.855286   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:08:55.502826   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:09:16.426244   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:09:47.442872   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
E0728 16:10:32.600091   11548 workload_cluster.go:354]  "msg"="unable to get kubeadmConfigMap" "error"="error getting kube-system/kubeadm-config configmap from target cluster: configmaps \"kubeadm-config\" not found"  
=== RUN   TestRemoveMachineFromKubeadmConfigMap/returns_error_if_unable_to_remove_api_endpoint_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/removes_the_machine_node_ref_from_kubeadm_config_for_Kubernetes_version_<_1.22.0
=== RUN   TestRemoveMachineFromKubeadmConfigMap/no_op_for_Kubernetes_version_>=_1.22.0
--- PASS: TestRemoveMachineFromKubeadmConfigMap (172.67s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_is_nil (0.00s)
    --- PASS: TestRemoveMachineFromKubeadmConfigMap/does_not_panic_if_machine_noderef_is_nil (0.00s)
... skipping 383 lines ...
I0728 16:07:47.849799   11867 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourcesetbinding" "worker count"=1
I0728 16:07:47.849904   11867 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"ConfigMap","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0728 16:07:47.953563   11867 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="clusterresourceset" "source"={"Type":{"kind":"Secret","apiVersion":"v1","metadata":{"creationTimestamp":null}}}
I0728 16:07:48.054076   11867 controller.go:162] controller-runtime/controller "msg"="Starting Controller" "controller"="clusterresourceset" 
I0728 16:07:48.054147   11867 controller.go:189] controller-runtime/controller "msg"="Starting workers" "controller"="clusterresourceset" "worker count"=1
I0728 16:07:48.153408   11867 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-f08209"} 
E0728 16:07:48.176741   11867 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"
•I0728 16:07:49.237205   11867 clusterresourcesetbinding_controller.go:84]  "msg"="deleting ClusterResourceSetBinding because the owner Cluster no longer exists" "clusterresourcesetbinding"={"Namespace":"default","Name":"cluster-e32r5r"} 
•E0728 16:07:49.289778   11867 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"
E0728 16:08:00.382322   11867 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.095 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
E0728 16:08:01.556272   11867 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"
•E0728 16:08:02.591669   11867 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"
E0728 16:08:03.616409   11867 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"
•I0728 16:08:03.619366   11867 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourceset" 
I0728 16:08:03.619421   11867 controller.go:203] controller-runtime/controller "msg"="Stopping workers" "controller"="clusterresourcesetbinding" 
I0728 16:08:03.619466   11867 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  



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 31.230 seconds
FAIL! -- 4 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestAPIs (31.23s)
FAIL
FAIL	sigs.k8s.io/cluster-api/exp/addons/controllers	31.290s
?   	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.01s)
    --- 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
E0728 16:07:36.966138   12054 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 91 lines ...
I0728 16:07:51.173039   12054 controller.go:155] controller-runtime/controller "msg"="Starting EventSource" "controller"="machinepool" "source"={"Type":{"metadata":{"creationTimestamp":null},"spec":{"clusterName":"","template":{"metadata":{},"spec":{"clusterName":"","bootstrap":{},"infrastructureRef":{}}}},"status":{"replicas":0,"bootstrapReady":false,"infrastructureReady":false}}}
I0728 16:07:51.197450   12054 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 16:07:51.232354   12054 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 16:07:51.234384   12054 machinepool_controller_phases.go:268]  "msg"="Infrastructure provider is not ready, requeuing" "cluster"="test-cluster" "machinepool"="machinepool-test" "namespace"="default" 
•I0728 16:07:51.251272   12054 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
•I0728 16:07:51.284976   12054 machinepool_controller_noderef.go:90]  "msg"="Cannot assign NodeRefs to MachinePool, no matching Nodes"  
••E0728 16:07:51.287757   12054 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 16:07:51.287821   12054 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-280184579/tls.crt: no such file or directory"  
E0728 16:07:51.287845   12054 certwatcher.go:143] controller-runtime/certwatcher "msg"="error re-watching file" "error"="no such file or directory"  
E0728 16:07:51.287865   12054 certwatcher.go:148] controller-runtime/certwatcher "msg"="error re-reading certificate" "error"="open /tmp/envtest-serving-certs-280184579/tls.crt: no such file or directory"  
I0728 16:07:51.287885   12054 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 9 of 9 Specs in 14.328 seconds
SUCCESS! -- 9 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestAPIs (14.33s)
PASS
ok  	sigs.k8s.io/cluster-api/exp/controllers	14.565s
?   	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 ...
I0728 16:08:17.459923   15114 server.go:199] controller-runtime/webhook "msg"="serving webhook server"  "host"="" "port"=42417
I0728 16:08:17.460053   15114 certwatcher.go:83] controller-runtime/certwatcher "msg"="Starting certificate watcher"  
••••••••••••••I0728 16:08:18.441863   15114 server.go:208] controller-runtime/webhook "msg"="shutting down webhook server"  


Ran 14 of 14 Specs in 7.598 seconds
SUCCESS! -- 14 Passed | 0 Failed | 0 Pending | 0 Skipped
--- PASS: TestPatch (7.60s)
=== 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 105 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.060s
FAIL
make: *** [Makefile:116: test] Error 1
+ EXIT_VALUE=2
+ set +o xtrace