Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1737443

Summary: MachineSet can endlessly create/delete new machinesets after it has been deleted.
Product: OpenShift Container Platform Reporter: Andrew McDermott <amcdermo>
Component: Cloud ComputeAssignee: Andrew McDermott <amcdermo>
Status: CLOSED ERRATA QA Contact: Jianwei Hou <jhou>
Severity: high Docs Contact:
Priority: medium    
Version: 4.2.0CC: agarcial, pthomas, zhsun
Target Milestone: ---   
Target Release: 4.2.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-10-16 06:34:43 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Andrew McDermott 2019-08-05 11:30:24 UTC 
When a machineset is being deleted it is possible to get into an
endless loop where new machine's are constantly recreated as the
reconciliation logic doesn't take into account the machine set's
deletion timestamp.

This has already been addressed in upstream: https://github.com/kubernetes-sigs/cluster-api/pull/953
Comment 1 Andrew McDermott 2019-08-05 12:46:27 UTC 
JIRA: https://jira.coreos.com/browse/CLOUD-623

which covers the PRs (for 4.2).
Comment 2 Andrew McDermott 2019-08-05 12:47:30 UTC 
PRs:

https://github.com/openshift/cluster-api/pull/58

https://github.com/openshift/cluster-api-provider-libvirt/pull/168
https://github.com/openshift/cluster-api-provider-kubemark/pull/27
https://github.com/openshift/cluster-api-provider-aws/pull/246
https://github.com/openshift/cluster-api-provider-azure/pull/65
https://github.com/openshift/cluster-api-provider-gcp/pull/45
Comment 4 sunzhaohua 2019-08-12 02:27:46 UTC 
Verified.

Clusterversion: 4.2.0-0.nightly-2019-08-08-103722

Tested in aws, azure, gcp. Check logs and machines, no new machines were created. 

aws: 
$ curl -X DELETE localhost:8080/apis/machine.openshift.io/v1beta1/namespaces/openshift-machine-api/machinesets/zhsun2-9pq8n-worker-us-east-2c -d '{"kind":"DeleteOptions","apiVersion":"v1","propagationPolicy":"Foreground"}' -H "Content-Type: application/json"

I0809 01:55:32.434701       1 controller.go:141] Reconciling Machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr"
I0809 01:55:32.434738       1 controller.go:310] Machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0809 01:55:32.434751       1 controller.go:205] Reconciling machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr" triggers delete
I0809 01:55:32.450857       1 info.go:20] cordoned node "ip-10-0-174-159.us-east-2.compute.internal"
I0809 01:55:32.513289       1 info.go:16] ignoring DaemonSet-managed pods: tuned-5zskq, dns-default-kbwqm, node-ca-szdsc, machine-config-daemon-st7fw, node-exporter-jjkvw, multus-q8r79, ovs-lzd9q, sdn-4gnpc; deleting pods with local storage: alertmanager-main-0, alertmanager-main-2, prometheus-k8s-0
I0809 01:55:35.551835       1 info.go:20] pod "alertmanager-main-0" removed (evicted)
I0809 01:55:35.566303       1 info.go:20] pod "router-default-6b6f98b85f-r4m5j" removed (evicted)
I0809 01:55:36.566070       1 info.go:20] pod "alertmanager-main-2" removed (evicted)
I0809 01:55:36.567173       1 info.go:20] pod "prometheus-k8s-0" removed (evicted)
I0809 01:55:36.567213       1 info.go:20] drained node "ip-10-0-174-159.us-east-2.compute.internal"
I0809 01:55:36.567229       1 controller.go:302] drain successful for machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr"
I0809 01:55:36.567264       1 actuator.go:332] zhsun2-9pq8n-worker-us-east-2c-rgmfr: deleting machine
I0809 01:55:36.729427       1 utils.go:151] Cleaning up extraneous instance for machine: i-0602de685f82cdf31, state: running, launchTime: 2019-08-09 01:47:24 +0000 UTC
I0809 01:55:36.729460       1 utils.go:155] Terminating i-0602de685f82cdf31 instance
I0809 01:55:36.875259       1 controller.go:225] Deleting node "ip-10-0-174-159.us-east-2.compute.internal" for machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr"
I0809 01:55:36.875657       1 reflector.go:123] Starting reflector *v1.Node (10m0s) from sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:204
I0809 01:55:36.875826       1 reflector.go:161] Listing and watching *v1.Node from sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:204
E0809 01:55:36.991042       1 controller.go:235] Failed to remove finalizer from machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr": Operation cannot be fulfilled on machines.machine.openshift.io "zhsun2-9pq8n-worker-us-east-2c-rgmfr": the object has been modified; please apply your changes to the latest version and try again
I0809 01:55:37.991376       1 controller.go:141] Reconciling Machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr"
I0809 01:55:37.991413       1 controller.go:310] Machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0809 01:55:37.991433       1 controller.go:205] Reconciling machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr" triggers delete
I0809 01:55:37.996938       1 controller.go:277] Could not find node from noderef, it may have already been deleted: ip-10-0-174-159.us-east-2.compute.internal
I0809 01:55:37.996965       1 actuator.go:332] zhsun2-9pq8n-worker-us-east-2c-rgmfr: deleting machine
W0809 01:55:38.100263       1 actuator.go:375] zhsun2-9pq8n-worker-us-east-2c-rgmfr: no instances found to delete for machine
I0809 01:55:38.100302       1 controller.go:225] Deleting node "ip-10-0-174-159.us-east-2.compute.internal" for machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr"
I0809 01:55:38.100340       1 controller.go:352] Node "ip-10-0-174-159.us-east-2.compute.internal" not found
I0809 01:55:38.112179       1 controller.go:239] Machine "zhsun2-9pq8n-worker-us-east-2c-rgmfr" deletion successful

azure:
$ curl -X DELETE localhost:8080/apis/machine.openshift.io/v1beta1/namespaces/openshift-machine-api/machinesets/zhsun7-2jp7b-worker-centralus3 -d '{"kind":"DeleteOptions","apiVersion":"v1","propagationPolicy":"Foreground"}' -H "Content-Type: application/json"

I0812 02:22:48.065503       1 controller.go:205] Reconciling machine "zhsun7-2jp7b-worker-centralus3-dnxhx" triggers delete
I0812 02:22:48.369936       1 info.go:16] ignoring DaemonSet-managed pods: tuned-9294m, dns-default-f2wsh, node-ca-lsdtb, busybox-6rvlp, machine-config-daemon-6dvwr, node-exporter-hcpws, multus-ll88p, ovs-nwf6x, sdn-cbqzn
I0812 02:22:48.369967       1 info.go:20] drained node "zhsun7-2jp7b-worker-centralus3-dnxhx"
I0812 02:22:48.369982       1 controller.go:302] drain successful for machine "zhsun7-2jp7b-worker-centralus3-dnxhx"
I0812 02:22:48.370007       1 actuator.go:128] Deleting machine zhsun7-2jp7b-worker-centralus3-dnxhx
I0812 02:22:48.371466       1 virtualmachines.go:225] deleting vm zhsun7-2jp7b-worker-centralus3-dnxhx 
E0812 02:22:48.709983       1 actuator.go:87] Machine error: failed to delete machine "zhsun7-2jp7b-worker-centralus3-dnxhx": failed to delete machine: compute.VirtualMachinesDeleteFuture: asynchronous operation has not completed
E0812 02:22:48.710014       1 controller.go:220] Failed to delete machine "zhsun7-2jp7b-worker-centralus3-dnxhx": requeue in: 1m0s
I0812 02:22:48.710029       1 controller.go:364] Actuator returned requeue-after error: requeue in: 1m0s
I0812 02:23:48.711943       1 controller.go:141] Reconciling Machine "zhsun7-2jp7b-worker-centralus3-dnxhx"
I0812 02:23:48.711986       1 controller.go:310] Machine "zhsun7-2jp7b-worker-centralus3-dnxhx" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0812 02:23:48.712004       1 controller.go:205] Reconciling machine "zhsun7-2jp7b-worker-centralus3-dnxhx" triggers delete
I0812 02:23:48.733293       1 controller.go:277] Could not find node from noderef, it may have already been deleted: zhsun7-2jp7b-worker-centralus3-dnxhx
I0812 02:23:48.733652       1 actuator.go:128] Deleting machine zhsun7-2jp7b-worker-centralus3-dnxhx
I0812 02:23:48.737026       1 virtualmachines.go:225] deleting vm zhsun7-2jp7b-worker-centralus3-dnxhx 
I0812 02:23:48.927734       1 virtualmachines.go:242] successfully deleted vm zhsun7-2jp7b-worker-centralus3-dnxhx 
I0812 02:23:48.927763       1 disks.go:49] deleting disk zhsun7-2jp7b-worker-centralus3-dnxhx_OSDisk
E0812 02:23:49.080729       1 actuator.go:87] Machine error: failed to delete machine "zhsun7-2jp7b-worker-centralus3-dnxhx": failed to delete OS disk: result error: compute.DisksDeleteFuture: asynchronous operation has not completed
E0812 02:23:49.080755       1 controller.go:220] Failed to delete machine "zhsun7-2jp7b-worker-centralus3-dnxhx": requeue in: 1m0s
I0812 02:23:49.080769       1 controller.go:364] Actuator returned requeue-after error: requeue in: 1m0s
I0812 02:24:49.081065       1 controller.go:141] Reconciling Machine "zhsun7-2jp7b-worker-centralus3-dnxhx"
I0812 02:24:49.081097       1 controller.go:310] Machine "zhsun7-2jp7b-worker-centralus3-dnxhx" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0812 02:24:49.081110       1 controller.go:205] Reconciling machine "zhsun7-2jp7b-worker-centralus3-dnxhx" triggers delete
I0812 02:24:49.087090       1 controller.go:277] Could not find node from noderef, it may have already been deleted: zhsun7-2jp7b-worker-centralus3-dnxhx
I0812 02:24:49.087137       1 actuator.go:128] Deleting machine zhsun7-2jp7b-worker-centralus3-dnxhx
I0812 02:24:49.087900       1 virtualmachines.go:225] deleting vm zhsun7-2jp7b-worker-centralus3-dnxhx 
I0812 02:24:49.254678       1 virtualmachines.go:242] successfully deleted vm zhsun7-2jp7b-worker-centralus3-dnxhx 
I0812 02:24:49.254732       1 disks.go:49] deleting disk zhsun7-2jp7b-worker-centralus3-dnxhx_OSDisk
I0812 02:24:49.282814       1 disks.go:65] successfully deleted disk zhsun7-2jp7b-worker-centralus3-dnxhx_OSDisk
I0812 02:24:49.282830       1 networkinterfaces.go:178] deleting nic zhsun7-2jp7b-worker-centralus3-dnxhx-nic
I0812 02:24:59.549605       1 networkinterfaces.go:197] successfully deleted nic zhsun7-2jp7b-worker-centralus3-dnxhx-nic
I0812 02:24:59.549630       1 publicips.go:102] deleting public ip zhsun7-2jp7b-zhsun7-2jp7b-worker-centralus3-dnxhx-publicip
I0812 02:24:59.588683       1 publicips.go:121] deleted public ip zhsun7-2jp7b-zhsun7-2jp7b-worker-centralus3-dnxhx-publicip
I0812 02:24:59.606705       1 controller.go:225] Deleting node "zhsun7-2jp7b-worker-centralus3-dnxhx" for machine "zhsun7-2jp7b-worker-centralus3-dnxhx"
I0812 02:24:59.606734       1 controller.go:352] Node "zhsun7-2jp7b-worker-centralus3-dnxhx" not found
I0812 02:24:59.632045       1 controller.go:239] Machine "zhsun7-2jp7b-worker-centralus3-dnxhx" deletion successful


gcp:
$ curl -X DELETE localhost:8080/apis/machine.openshift.io/v1beta1/namespaces/openshift-machine-api/machinesets/zhsun0-nks2r-w-c -d '{"kind":"DeleteOptions","apiVersion":"v1","propagationPolicy":"Foreground"}' -H "Content-Type: application/json"

I0812 02:13:51.959048       1 controller.go:205] Reconciling machine "zhsun0-nks2r-w-c-j2tpw" triggers delete
I0812 02:13:52.014155       1 info.go:16] ignoring DaemonSet-managed pods: tuned-r5wt4, dns-default-pjpdc, node-ca-6x8vs, machine-config-daemon-tmm2s, node-exporter-grvtj, multus-n2srd, ovs-mbv4j, sdn-25lr8
I0812 02:13:52.014182       1 info.go:20] drained node "zhsun0-nks2r-w-c-j2tpw.c.openshift-gce-devel.internal"
I0812 02:13:52.014196       1 controller.go:302] drain successful for machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:13:52.014230       1 actuator.go:116] zhsun0-nks2r-w-c-j2tpw: Deleting machine
I0812 02:13:52.333098       1 reconciler.go:253] Machine "zhsun0-nks2r-w-c-j2tpw" already exists
I0812 02:13:52.746745       1 reconciler.go:281] zhsun0-nks2r-w-c-j2tpw: machine status is exists, requeuing...
E0812 02:13:52.746813       1 controller.go:220] Failed to delete machine "zhsun0-nks2r-w-c-j2tpw": requeue in: 20s
I0812 02:13:52.746822       1 controller.go:364] Actuator returned requeue-after error: requeue in: 20s
I0812 02:14:12.747141       1 controller.go:141] Reconciling Machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:12.747181       1 controller.go:310] Machine "zhsun0-nks2r-w-c-j2tpw" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0812 02:14:12.747198       1 controller.go:205] Reconciling machine "zhsun0-nks2r-w-c-j2tpw" triggers delete
I0812 02:14:12.797535       1 info.go:16] ignoring DaemonSet-managed pods: tuned-r5wt4, dns-default-pjpdc, node-ca-6x8vs, machine-config-daemon-tmm2s, node-exporter-grvtj, multus-n2srd, ovs-mbv4j, sdn-25lr8
I0812 02:14:12.797565       1 info.go:20] drained node "zhsun0-nks2r-w-c-j2tpw.c.openshift-gce-devel.internal"
I0812 02:14:12.797579       1 controller.go:302] drain successful for machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:12.797624       1 actuator.go:116] zhsun0-nks2r-w-c-j2tpw: Deleting machine
I0812 02:14:13.173382       1 reconciler.go:253] Machine "zhsun0-nks2r-w-c-j2tpw" already exists
I0812 02:14:13.678243       1 reconciler.go:281] zhsun0-nks2r-w-c-j2tpw: machine status is exists, requeuing...
E0812 02:14:13.678346       1 controller.go:220] Failed to delete machine "zhsun0-nks2r-w-c-j2tpw": requeue in: 20s
I0812 02:14:13.678358       1 controller.go:364] Actuator returned requeue-after error: requeue in: 20s
I0812 02:14:33.678655       1 controller.go:141] Reconciling Machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:33.678700       1 controller.go:310] Machine "zhsun0-nks2r-w-c-j2tpw" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0812 02:14:33.678717       1 controller.go:205] Reconciling machine "zhsun0-nks2r-w-c-j2tpw" triggers delete
I0812 02:14:33.732506       1 info.go:16] ignoring DaemonSet-managed pods: tuned-r5wt4, dns-default-pjpdc, node-ca-6x8vs, machine-config-daemon-tmm2s, node-exporter-grvtj, multus-n2srd, ovs-mbv4j, sdn-25lr8
I0812 02:14:33.732534       1 info.go:20] drained node "zhsun0-nks2r-w-c-j2tpw.c.openshift-gce-devel.internal"
I0812 02:14:33.732548       1 controller.go:302] drain successful for machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:33.732577       1 actuator.go:116] zhsun0-nks2r-w-c-j2tpw: Deleting machine
I0812 02:14:34.139729       1 reconciler.go:253] Machine "zhsun0-nks2r-w-c-j2tpw" already exists
I0812 02:14:34.607021       1 reconciler.go:281] zhsun0-nks2r-w-c-j2tpw: machine status is exists, requeuing...
E0812 02:14:34.607097       1 controller.go:220] Failed to delete machine "zhsun0-nks2r-w-c-j2tpw": requeue in: 20s
I0812 02:14:34.607108       1 controller.go:364] Actuator returned requeue-after error: requeue in: 20s
I0812 02:14:54.607338       1 controller.go:141] Reconciling Machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:54.607380       1 controller.go:310] Machine "zhsun0-nks2r-w-c-j2tpw" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0812 02:14:54.607393       1 controller.go:205] Reconciling machine "zhsun0-nks2r-w-c-j2tpw" triggers delete
I0812 02:14:54.659787       1 info.go:16] ignoring DaemonSet-managed pods: tuned-r5wt4, dns-default-pjpdc, node-ca-6x8vs, machine-config-daemon-tmm2s, node-exporter-grvtj, multus-n2srd, ovs-mbv4j, sdn-25lr8
I0812 02:14:54.659833       1 info.go:20] drained node "zhsun0-nks2r-w-c-j2tpw.c.openshift-gce-devel.internal"
I0812 02:14:54.659848       1 controller.go:302] drain successful for machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:54.659872       1 actuator.go:116] zhsun0-nks2r-w-c-j2tpw: Deleting machine
I0812 02:14:55.025536       1 reconciler.go:250] Machine "zhsun0-nks2r-w-c-j2tpw" is considered as non existent as its status is "TERMINATED"
I0812 02:14:55.025577       1 reconciler.go:275] zhsun0-nks2r-w-c-j2tpw: Machine not found during delete, skipping
I0812 02:14:55.025618       1 controller.go:225] Deleting node "zhsun0-nks2r-w-c-j2tpw.c.openshift-gce-devel.internal" for machine "zhsun0-nks2r-w-c-j2tpw"
I0812 02:14:55.044655       1 controller.go:239] Machine "zhsun0-nks2r-w-c-j2tpw" deletion successful

Tested in aws with clusterversion 4.1.0-0.nightly-2019-08-06-201533, new machine was created.
$ oc get machine
NAME                                                 INSTANCE              STATE     TYPE       REGION           ZONE              AGE
qe-anusaxen-151-bspgn-master-0                       i-0f94cbcd41f5769ea   running   m5.large   ap-northeast-1   ap-northeast-1a   11h
qe-anusaxen-151-bspgn-master-1                       i-094bc20936832528e   running   m5.large   ap-northeast-1   ap-northeast-1c   11h
qe-anusaxen-151-bspgn-master-2                       i-069e4c715c03fc12f   running   m5.large   ap-northeast-1   ap-northeast-1d   11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1a-pjkbz   i-05680c9d576b377a5   running   m5.large   ap-northeast-1   ap-northeast-1a   11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1c-vz67p   i-0163632d615427b56   running   m5.large   ap-northeast-1   ap-northeast-1c   11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc   i-04e629282e07d7a1f   running   m5.large   ap-northeast-1   ap-northeast-1d   11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk                                   m5.large   ap-northeast-1   ap-northeast-1d   3s

$ oc get machineset
NAME                                           DESIRED   CURRENT   READY   AVAILABLE   AGE
qe-anusaxen-151-bspgn-worker-ap-northeast-1a   1         1         1       1           11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1c   1         1         1       1           11h
qe-anusaxen-151-bspgn-worker-ap-northeast-1d   1         1                             11h


I0809 01:31:00.297897       1 controller.go:129] Reconciling Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc"
I0809 01:31:00.297921       1 controller.go:292] Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0809 01:31:00.297935       1 controller.go:193] Reconciling machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc" triggers delete
I0809 01:31:00.334618       1 info.go:20] cordoned node "ip-10-0-162-178.ap-northeast-1.compute.internal"
I0809 01:31:00.407272       1 info.go:16] ignoring DaemonSet-managed pods: tuned-zldj5, dns-default-bpkfb, node-ca-m8k4l, machine-config-daemon-8vr5q, node-exporter-hwrmn, multus-64wlx, ovs-jnxnw, sdn-4j9fz; deleting pods with local storage: alertmanager-main-1, prometheus-adapter-549976d7-djcwp, prometheus-k8s-0
I0809 01:31:00.618564       1 info.go:20] pod "alertmanager-main-1" removed (evicted)
I0809 01:31:08.562330       1 info.go:20] pod "prometheus-operator-684bd89df8-pwnsk" removed (evicted)
I0809 01:31:08.595910       1 info.go:20] pod "router-default-785956dbb9-btqnt" removed (evicted)
I0809 01:31:08.612281       1 info.go:20] pod "prometheus-adapter-549976d7-djcwp" removed (evicted)
I0809 01:31:09.592173       1 info.go:20] pod "prometheus-k8s-0" removed (evicted)
I0809 01:31:09.592225       1 info.go:20] drained node "ip-10-0-162-178.ap-northeast-1.compute.internal"
I0809 01:31:09.592237       1 controller.go:284] drain successful for machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc"
I0809 01:31:09.592276       1 actuator.go:245] deleting machine
I0809 01:31:09.814008       1 utils.go:151] Cleaning up extraneous instance for machine: i-04e629282e07d7a1f, state: running, launchTime: 2019-08-08 14:30:46 +0000 UTC
I0809 01:31:09.814035       1 utils.go:155] Terminating i-04e629282e07d7a1f instance
I0809 01:31:09.930063       1 controller.go:212] Deleting node "ip-10-0-162-178.ap-northeast-1.compute.internal" for machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc"
I0809 01:31:09.930804       1 reflector.go:131] Starting reflector *v1.Node (10m0s) from sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:196
I0809 01:31:09.930825       1 reflector.go:169] Listing and watching *v1.Node from sigs.k8s.io/controller-runtime/pkg/cache/internal/informers_map.go:196
I0809 01:31:10.128553       1 controller.go:226] Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-87mhc" deletion successful
I0809 01:31:10.128641       1 controller.go:129] Reconciling Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk"
I0809 01:31:10.128650       1 controller.go:292] Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0809 01:31:10.142932       1 controller.go:129] Reconciling Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk"
I0809 01:31:10.142951       1 controller.go:292] Machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk" in namespace "openshift-machine-api" doesn't specify "cluster.k8s.io/cluster-name" label, assuming nil cluster
I0809 01:31:10.142963       1 actuator.go:378] Checking if machine exists
I0809 01:31:10.187210       1 actuator.go:386] Instance does not exist
I0809 01:31:10.187231       1 controller.go:246] Reconciling machine object qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk triggers idempotent create.
I0809 01:31:10.187238       1 actuator.go:110] creating machine
E0809 01:31:10.187865       1 utils.go:186] NodeRef not found in machine qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk
I0809 01:31:10.204822       1 instances.go:44] No stopped instances found for machine qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk
I0809 01:31:10.205189       1 instances.go:141] Using AMI ami-0c63b39219b8123e5
I0809 01:31:10.205277       1 instances.go:73] Describing security groups based on filters
I0809 01:31:10.317865       1 instances.go:118] Describing subnets based on filters
I0809 01:31:12.107341       1 actuator.go:475] Updating status
I0809 01:31:12.107362       1 actuator.go:519] finished calculating AWS status
I0809 01:31:12.107416       1 actuator.go:144] machine status has changed, updating
E0809 01:31:12.113277       1 actuator.go:149] error updating machine status: Operation cannot be fulfilled on machines.machine.openshift.io "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk": StorageError: invalid object, Code: 4, Key: /kubernetes.io/machine.openshift.io/machines/openshift-machine-api/qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk, ResourceVersion: 0, AdditionalErrorMsg: Precondition failed: UID in precondition: 57f989b2-ba45-11e9-9747-0ac69daba5b8, UID in object meta: 
W0809 01:31:12.113322       1 controller.go:248] Failed to create machine "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk": Operation cannot be fulfilled on machines.machine.openshift.io "qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk": StorageError: invalid object, Code: 4, Key: /kubernetes.io/machine.openshift.io/machines/openshift-machine-api/qe-anusaxen-151-bspgn-worker-ap-northeast-1d-c9sgk, ResourceVersion: 0, AdditionalErrorMsg: Precondition failed: UID in precondition: 57f989b2-ba45-11e9-9747-0ac69daba5b8, UID in object meta:
Comment 5 errata-xmlrpc 2019-10-16 06:34:43 UTC 
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2019:2922