Description of problem: Delete a machine, in machine controller log one line printed as: ``` I0219 10:10:31.033535 1 controller.go:361] "qe-jhou-rqfpj-worker-centralus2-tqdvz": Node "qe-jhou-rqfpj-worker-centralus2-tqdvz" is unreachable, draining will wait 'Ĭ' seconds after pod is signalled for deletion and skip after it ``` Version-Release number of selected component (if applicable): 4.4.0-0.nightly-2020-02-18-211831(IPI Azure) How reproducible: Always Steps to Reproduce: 1. Delete a machine 2. oc -n openshift-machine-api logs machine-api-controllers-75cbb7f444-rkqpl -c machine-controller -f Actual results: Got log: "draining will wait 'Ĭ' seconds after" Expected results: The waiting second printed correctly Additional info:
Description of problem: Delete a machine, in machine controller log one line printed as: ``` I0219 10:10:31.033535 1 controller.go:361] "qe-jhou-rqfpj-worker-centralus2-tqdvz": Node "qe-jhou-rqfpj-worker-centralus2-tqdvz" is unreachable, draining will wait 'Ĭ' seconds after pod is signalled for deletion and skip after it ``` NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.5.0-0.nightly-2020-03-12-041748 True False 89m Cluster version is 4.5.0-0.nightly-2020-03-12-041748 How reproducible: Always Steps to Reproduce: 1. Delete a machine 2. oc -n openshift-machine-api logs machine-api-controllers-75cbb7f444-rkqpl -c machine-controller -f Actual results: Got log: "I0312 08:57:12.120631 1 controller.go:361] "zhsun9-l4nxj-worker-westus-snk6x": Node "zhsun9-l4nxj-worker-westus-snk6x" is unreachable, draining will wait 'Ĭ' seconds after pod is signalled for deletion and skip after it I0312 08:57:33.327193 1 controller.go:361] "zhsun9-l4nxj-worker-westus-snk6x": Node "zhsun9-l4nxj-worker-westus-snk6x" is unreachable, draining will wait 'Ĭ' seconds after pod is signalled for deletion and skip after it Expected results: The waiting second printed correctly Additional info:
https://github.com/openshift/cluster-api-provider-azure/pull/111 https://github.com/openshift/machine-api-operator/pull/495 https://github.com/openshift/cluster-api-provider-aws/pull/300 https://github.com/openshift/cluster-api-provider-aws/pull/300
https://github.com/openshift/cluster-api-provider-gcp/pull/76
Validated on : [miyadav@miyadav ManualRun]$ oc get clusterversion NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.5.0-0.nightly-2020-04-21-103613 True False 25m Cluster version is 4.5.0-0.nightly-2020-04-21-103613 Reproducible Always. Steps to Reproduce: 1. Delete a machine 2. oc logs -f machine-api-controllers-788f58b4-jl9bj -c machine-controller Actual results: Got log: I0424 08:34:37.941409 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-mwnhx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"39778"} "reason"="Updated" I0424 08:35:19.553512 1 controller.go:163] miyadav-jpfdm-worker-westus-kbdsp: reconciling Machine I0424 08:35:19.553550 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-kbdsp exists I0424 08:35:19.595738 1 controller.go:73] controllers/MachineSet "msg"="Reconciling" "machineset"="miyadav-jpfdm-worker-westus" "namespace"="openshift-machine-api" I0424 08:35:19.630581 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machineset" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus"} I0424 08:35:24.931161 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-kbdsp I0424 08:35:24.931189 1 controller.go:419] miyadav-jpfdm-worker-westus-kbdsp: going into phase "Failed" I0424 08:35:24.945906 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-kbdsp"} I0424 08:35:24.946009 1 controller.go:163] miyadav-jpfdm-worker-westus-kbdsp: reconciling Machine W0424 08:35:24.946028 1 controller.go:260] miyadav-jpfdm-worker-westus-kbdsp: machine has gone "Failed" phase. It won't reconcile I0424 08:35:24.946058 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-kbdsp"}. . . . Expected results: The waiting second printed correctly Additional info: The deleted machine went to failed status : oc get machines . . miyadav-jpfdm-worker-westus-kbdsp Failed Standard_D2s_v3 westus 97m . . Although the machine status is shown as failed in openshift GUI and from command line tool (oc) , the machine is successfully deleted from Azure (showing as deleted in Azure GUI). [could be related to - https://bugzilla.redhat.com/show_bug.cgi?id=1827589 ] The drain seems to have happened successfully and I didn't hit the path for log -- . . "I0312 08:57:33.327193 1 controller.go:361] "zhsun9-l4nxj-worker-westus-snk6x": Node "zhsun9-l4nxj-worker-westus-snk6x" is unreachable, draining will wait 'Ĭ' seconds after pod is signalled for deletion and skip after it" . . Have tried multiple times but couldn't reproduce. Hence not Verifying it. Please have a look and provide more info , if it needs some PR to be merged before testing again.
would you please try again deleting an existing machine and share full machine controller logs?
Here are full logs : will ping you env details over slack , just in case you want to check in the env too . I0424 08:52:12.954213 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:12.954242 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:52:12.954249 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:13.730807 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:52:13.804777 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:13.804836 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:13.804842 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:52:13.820723 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:52:13.820753 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:52:13.820767 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:52:13.820847 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:52:31.473043 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:52:31.473071 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:52:31.926008 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:31.926036 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:52:31.926041 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:32.865821 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:52:32.914256 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:32.914409 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:32.914415 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:52:32.933299 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:52:32.933322 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:52:32.933333 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:52:32.933388 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:52:52.933656 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:52:52.933685 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:52:53.345006 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:53.345033 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:52:53.345040 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:52:54.226071 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:52:54.342997 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:54.343035 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:52:54.343041 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:52:54.366607 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:52:54.366636 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:52:54.366647 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:52:54.366738 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:53:14.366886 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:53:14.366929 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:53:14.885426 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:14.885452 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:53:14.885458 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:15.969306 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:53:16.035953 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:16.035989 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:16.036064 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:53:16.052157 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:53:16.052180 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:53:16.052195 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:53:16.052230 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:53:36.052387 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:53:36.052416 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:53:36.362199 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:36.362321 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:53:36.362356 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:37.479560 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:53:37.601444 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:37.601475 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:37.601480 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:53:37.621801 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:53:37.621823 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:53:37.621833 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:53:37.621889 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:53:57.622049 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:53:57.622077 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:53:58.087865 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:58.087897 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:53:58.087905 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:53:58.977509 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:53:59.137127 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:59.137172 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:53:59.137182 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:53:59.153078 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:53:59.153099 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:53:59.153107 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:53:59.153148 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:54:19.153310 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:54:19.153338 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:54:19.500604 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:19.500632 1 controller.go:307] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent create I0424 08:54:19.500638 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:20.309399 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-jx8zx-nic I0424 08:54:20.358323 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:20.358356 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:20.358400 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:54:20.374860 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-jx8zx"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile W0424 08:54:20.374884 1 controller.go:309] miyadav-jpfdm-worker-westus-jx8zx: failed to create machine: requeue in: 20s I0424 08:54:20.374898 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 08:54:20.374946 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-jx8zx\"s: failed to create vm miyadav-jpfdm-worker-westus-jx8zx : vm miyadav-jpfdm-worker-westus-jx8zx is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="FailedCreate" I0424 08:54:40.375224 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:54:40.375251 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:54:40.835030 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:40.835052 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:54:40.835062 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:54:40.835067 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:41.275456 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine E0424 08:54:41.300403 1 controller.go:278] miyadav-jpfdm-worker-westus-jx8zx: instance exists but providerID or addresses has not been given to the machine yet, requeuing I0424 08:54:41.300454 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:54:41.300461 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:54:41.300529 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"46687"} "reason"="Updated" I0424 08:54:42.059825 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:42.059849 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:54:42.059859 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:54:42.059864 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:42.575814 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:42.575871 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:42.575879 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:54:42.591337 1 controller.go:419] miyadav-jpfdm-worker-westus-jx8zx: going into phase "Provisioned" I0424 08:54:42.591470 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47498"} "reason"="Updated" I0424 08:54:42.607410 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:54:42.607465 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:54:42.607472 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:54:43.015400 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:43.015422 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:54:43.015432 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:54:43.015437 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:54:43.455031 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:43.455089 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:54:43.455095 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:54:43.472325 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:54:43.472415 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:55:11.300668 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:55:11.300696 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:55:11.673574 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:55:11.673603 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:55:11.673613 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:55:11.673618 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:55:12.197648 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:55:12.197687 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:55:12.197692 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:55:12.215575 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:55:12.215667 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:55:42.215832 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:55:42.215863 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:55:42.685353 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:55:42.685375 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:55:42.685384 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:55:42.685389 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:55:43.022329 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:55:43.022366 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:55:43.022370 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:55:43.039812 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:55:43.039894 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:56:13.040023 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:56:13.040050 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:56:13.494568 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:56:13.494593 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:56:13.494604 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:56:13.494611 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:56:14.097531 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:56:14.097734 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:56:14.097754 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:56:14.114498 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:56:14.114579 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:56:44.114765 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:56:44.114802 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:56:44.574994 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:56:44.575020 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:56:44.575032 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:56:44.575039 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:56:45.020435 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:56:45.020472 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:56:45.020477 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:56:45.037271 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:56:45.037359 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:57:15.037510 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:57:15.037541 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:57:15.444562 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:57:15.444587 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:57:15.444599 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:57:15.444606 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:57:15.963340 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:57:15.963389 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:57:15.963396 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:57:15.978996 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:57:15.979081 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:57:45.979245 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:57:45.979275 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:57:46.364522 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:57:46.364544 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:57:46.364553 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:57:46.364558 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:57:46.933466 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:57:46.933513 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:57:46.933519 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:57:46.950162 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:57:46.950234 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:58:16.950441 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:58:16.950472 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:58:17.390535 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:17.390557 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:58:17.390567 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:58:17.390571 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:17.823740 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:17.823776 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:17.823781 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:58:17.846189 1 controller.go:287] miyadav-jpfdm-worker-westus-jx8zx: has no node yet, requeuing I0424 08:58:17.846257 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"47506"} "reason"="Updated" I0424 08:58:44.161642 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:58:44.161668 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:58:44.532309 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:44.532336 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:58:44.532346 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:58:44.532351 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:45.030307 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:45.030345 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:45.030350 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:58:45.051005 1 controller.go:419] miyadav-jpfdm-worker-westus-jx8zx: going into phase "Running" I0424 08:58:45.051144 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"48879"} "reason"="Updated" I0424 08:58:45.065301 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-jx8zx"} I0424 08:58:45.065441 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:58:45.065458 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:58:45.294115 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:45.294138 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:58:45.294149 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:58:45.294154 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:45.783554 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:45.783596 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:45.783603 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:58:45.800047 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-jx8zx"} I0424 08:58:45.800108 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"48935"} "reason"="Updated" I0424 08:58:47.846422 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 08:58:47.846449 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 08:58:48.156172 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:48.156227 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 08:58:48.156237 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 08:58:48.156242 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 08:58:48.538555 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:48.538601 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 08:58:48.538610 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 08:58:48.559247 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-jx8zx"} I0424 08:58:48.559312 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"48935"} "reason"="Updated" I0424 09:00:15.066449 1 controller.go:163] miyadav-jpfdm-worker-westus-jx8zx: reconciling Machine I0424 09:00:15.066479 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-jx8zx exists I0424 09:00:15.080370 1 controller.go:73] controllers/MachineSet "msg"="Reconciling" "machineset"="miyadav-jpfdm-worker-westus" "namespace"="openshift-machine-api" I0424 09:00:15.095820 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machineset" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus"} I0424 09:00:15.499274 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-jx8zx I0424 09:00:15.499297 1 reconciler.go:372] Machine e7a41736-34c9-4b3b-b511-49db50281abc is running I0424 09:00:15.499310 1 controller.go:271] miyadav-jpfdm-worker-westus-jx8zx: reconciling machine triggers idempotent update I0424 09:00:15.499317 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-jx8zx I0424 09:00:16.004793 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 09:00:16.004842 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-jx8zx: status unchanged I0424 09:00:16.004848 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-jx8zx: patching machine I0424 09:00:16.025551 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-jx8zx"} I0424 09:00:16.025624 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-jx8zx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-jx8zx","uid":"9d3049f3-57f5-4c3c-950f-79bc27a5dbd8","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"49538"} "reason"="Updated" I0424 10:31:33.877580 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:31:33.877613 1 controller.go:419] miyadav-jpfdm-worker-westus-mwnhx: going into phase "Deleting" I0424 10:31:33.890053 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:31:33.927587 1 controller.go:73] controllers/MachineSet "msg"="Reconciling" "machineset"="miyadav-jpfdm-worker-westus" "namespace"="openshift-machine-api" I0424 10:31:33.937011 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machineset" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus"} I0424 10:31:33.948901 1 controller.go:73] controllers/MachineSet "msg"="Reconciling" "machineset"="miyadav-jpfdm-worker-westus" "namespace"="openshift-machine-api" I0424 10:31:33.956657 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machineset" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus"} I0424 10:31:34.012411 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq I0424 10:31:34.012422 1 controller.go:468] evicting pod openshift-cluster-storage-operator/csi-snapshot-controller-operator-84547858b5-66q96 I0424 10:31:34.012455 1 controller.go:468] evicting pod openshift-cluster-storage-operator/csi-snapshot-controller-7b8f76846d-5sdvf I0424 10:31:34.012471 1 controller.go:468] evicting pod openshift-image-registry/image-registry-5b6cc796bc-t4rb5 I0424 10:31:34.012482 1 controller.go:468] evicting pod openshift-monitoring/openshift-state-metrics-786cbff76-4ml46 I0424 10:31:34.012515 1 controller.go:468] evicting pod openshift-monitoring/alertmanager-main-0 I0424 10:31:34.012556 1 controller.go:468] evicting pod openshift-kube-storage-version-migrator/migrator-6dbc9bc7bc-j5mmv I0424 10:31:34.012613 1 controller.go:468] evicting pod openshift-monitoring/prometheus-adapter-64f6c8f478-6pfcx I0424 10:31:34.012627 1 controller.go:468] evicting pod openshift-monitoring/telemeter-client-7bfb5d6cb-687d8 I0424 10:31:34.012564 1 controller.go:468] evicting pod openshift-monitoring/prometheus-k8s-1 I0424 10:31:34.012587 1 controller.go:468] evicting pod openshift-monitoring/grafana-cb59bb8d5-lr8n8 I0424 10:31:34.012742 1 controller.go:468] evicting pod openshift-monitoring/prometheus-adapter-64f6c8f478-vw9rg I0424 10:31:34.012905 1 controller.go:468] evicting pod openshift-monitoring/thanos-querier-56485688f8-q4vjw I0424 10:31:44.093625 1 controller.go:352] Evicted pod from Nodepodcsi-snapshot-controller-operator-84547858b5-66q96/openshift-cluster-storage-operator I0424 10:31:44.094298 1 controller.go:352] Evicted pod from Nodepodtelemeter-client-7bfb5d6cb-687d8/openshift-monitoring I0424 10:31:44.241626 1 controller.go:352] Evicted pod from Nodepodopenshift-state-metrics-786cbff76-4ml46/openshift-monitoring I0424 10:31:44.284008 1 controller.go:352] Evicted pod from Nodepodprometheus-k8s-1/openshift-monitoring I0424 10:31:44.320494 1 controller.go:352] Evicted pod from Nodepodimage-registry-5b6cc796bc-t4rb5/openshift-image-registry I0424 10:31:44.429503 1 controller.go:352] Evicted pod from Nodepodthanos-querier-56485688f8-q4vjw/openshift-monitoring I0424 10:31:45.081413 1 controller.go:352] Evicted pod from Nodepodcsi-snapshot-controller-7b8f76846d-5sdvf/openshift-cluster-storage-operator I0424 10:31:45.092110 1 controller.go:352] Evicted pod from Nodepodprometheus-adapter-64f6c8f478-vw9rg/openshift-monitoring I0424 10:31:45.123305 1 controller.go:352] Evicted pod from Nodepodgrafana-cb59bb8d5-lr8n8/openshift-monitoring I0424 10:31:45.123590 1 controller.go:352] Evicted pod from Nodepodprometheus-adapter-64f6c8f478-6pfcx/openshift-monitoring I0424 10:31:45.134398 1 controller.go:352] Evicted pod from Nodepodmigrator-6dbc9bc7bc-j5mmv/openshift-kube-storage-version-migrator I0424 10:31:45.158844 1 controller.go:352] Evicted pod from Nodepodalertmanager-main-0/openshift-monitoring W0424 10:31:54.359871 1 controller.go:374] drain failed for machine "miyadav-jpfdm-worker-westus-mwnhx": error when waiting for pod "router-default-68dbf78447-hvgsq" terminating: global timeout reached: 20s E0424 10:31:54.359927 1 controller.go:211] miyadav-jpfdm-worker-westus-mwnhx: failed to drain node for machine: requeue in: 20s I0424 10:31:54.359947 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:31:54.360010 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:31:54.374565 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-rdl6b"} I0424 10:31:54.374616 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:31:54.374628 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:31:54.469982 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq E0424 10:31:54.486455 1 controller.go:468] error when evicting pod "router-default-68dbf78447-hvgsq" (will retry after 5s): Cannot evict pod as it would violate the pod's disruption budget. I0424 10:31:59.486712 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq E0424 10:31:59.497794 1 controller.go:468] error when evicting pod "router-default-68dbf78447-hvgsq" (will retry after 5s): Cannot evict pod as it would violate the pod's disruption budget. I0424 10:32:04.497961 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq E0424 10:32:04.509819 1 controller.go:468] error when evicting pod "router-default-68dbf78447-hvgsq" (will retry after 5s): Cannot evict pod as it would violate the pod's disruption budget. I0424 10:32:09.510017 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq E0424 10:32:09.519566 1 controller.go:468] error when evicting pod "router-default-68dbf78447-hvgsq" (will retry after 5s): Cannot evict pod as it would violate the pod's disruption budget. I0424 10:32:14.519744 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq W0424 10:32:14.519899 1 controller.go:374] drain failed for machine "miyadav-jpfdm-worker-westus-mwnhx": error when evicting pod "router-default-68dbf78447-hvgsq": global timeout reached: 20s E0424 10:32:14.520001 1 controller.go:211] miyadav-jpfdm-worker-westus-mwnhx: failed to drain node for machine: requeue in: 20s I0424 10:32:14.520017 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:32:14.520102 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:32:14.520119 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:32:15.119257 1 controller.go:419] miyadav-jpfdm-worker-westus-rdl6b: going into phase "Provisioning" I0424 10:32:15.134605 1 controller.go:307] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent create I0424 10:32:15.134640 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:32:16.376032 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:32:16.429171 1 virtualmachines.go:73] getting nic miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:32:16.581199 1 virtualmachines.go:82] got nic miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:32:16.581221 1 virtualmachines.go:84] creating vm miyadav-jpfdm-worker-westus-rdl6b I0424 10:32:17.993519 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:32:18.015087 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-rdl6b"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : failed to create or get machine: compute.VirtualMachinesCreateOrUpdateFuture: asynchronous operation has not completed W0424 10:32:18.015112 1 controller.go:309] miyadav-jpfdm-worker-westus-rdl6b: failed to create machine: requeue in: 20s I0424 10:32:18.015122 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:32:18.015169 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:32:18.015185 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:32:18.016235 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-rdl6b\"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : failed to create or get machine: compute.VirtualMachinesCreateOrUpdateFuture: asynchronous operation has not completed" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81497"} "reason"="FailedCreate" I0424 10:32:18.107702 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq W0424 10:32:38.143233 1 controller.go:374] drain failed for machine "miyadav-jpfdm-worker-westus-mwnhx": error when waiting for pod "router-default-68dbf78447-hvgsq" terminating: global timeout reached: 20s E0424 10:32:38.143278 1 controller.go:211] miyadav-jpfdm-worker-westus-mwnhx: failed to drain node for machine: requeue in: 20s I0424 10:32:38.143292 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:32:38.143362 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:32:38.143371 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:32:38.657359 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:32:38.657394 1 controller.go:307] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent create I0424 10:32:38.657401 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:32:39.786684 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:32:39.926187 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:32:39.951608 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-rdl6b"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile W0424 10:32:39.951712 1 controller.go:309] miyadav-jpfdm-worker-westus-rdl6b: failed to create machine: requeue in: 20s I0424 10:32:39.951732 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:32:39.951790 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:32:39.951811 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:32:39.952117 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-rdl6b\"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81531"} "reason"="FailedCreate" I0424 10:32:40.040236 1 controller.go:468] evicting pod openshift-ingress/router-default-68dbf78447-hvgsq I0424 10:32:53.083530 1 controller.go:352] Evicted pod from Nodepodrouter-default-68dbf78447-hvgsq/openshift-ingress I0424 10:32:53.083583 1 controller.go:378] drain successful for machine "miyadav-jpfdm-worker-westus-mwnhx" I0424 10:32:53.083623 1 actuator.go:128] Deleting machine miyadav-jpfdm-worker-westus-mwnhx I0424 10:32:53.083761 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Node \"miyadav-jpfdm-worker-westus-mwnhx\" drained" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"80722"} "reason"="Deleted" I0424 10:32:53.084696 1 virtualmachines.go:225] deleting vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:32:53.685198 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-mwnhx: patching machine E0424 10:32:53.710330 1 actuator.go:79] Machine error: failed to delete machine "miyadav-jpfdm-worker-westus-mwnhx": failed to delete machine: compute.VirtualMachinesDeleteFuture: asynchronous operation has not completed E0424 10:32:53.710360 1 controller.go:224] miyadav-jpfdm-worker-westus-mwnhx: failed to delete machine: requeue in: 20s I0424 10:32:53.710370 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:32:53.710416 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:32:53.710425 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:32:53.710461 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="DeleteError: failed to delete machine \"miyadav-jpfdm-worker-westus-mwnhx\": failed to delete machine: compute.VirtualMachinesDeleteFuture: asynchronous operation has not completed" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"80722"} "reason"="FailedDelete" I0424 10:33:04.816830 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:04.816858 1 controller.go:307] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent create I0424 10:33:04.816864 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:21.122726 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:33:31.331566 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:31.331610 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:31.331616 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:33:31.348547 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-rdl6b"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile W0424 10:33:31.348567 1 controller.go:309] miyadav-jpfdm-worker-westus-rdl6b: failed to create machine: requeue in: 20s I0424 10:33:31.348578 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:33:31.348622 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:33:31.348633 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:33:31.348689 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-rdl6b\"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81693"} "reason"="FailedCreate" I0424 10:33:31.355191 1 controller.go:332] Could not find node from noderef, it may have already been deleted: miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:31.355208 1 actuator.go:128] Deleting machine miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:31.355724 1 virtualmachines.go:225] deleting vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:31.875979 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:33:31.876015 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:33:31.876020 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-mwnhx: patching machine E0424 10:33:31.893325 1 actuator.go:79] Machine error: failed to delete machine "miyadav-jpfdm-worker-westus-mwnhx": failed to delete machine: compute.VirtualMachinesDeleteFuture: asynchronous operation has not completed E0424 10:33:31.893360 1 controller.go:224] miyadav-jpfdm-worker-westus-mwnhx: failed to delete machine: requeue in: 20s I0424 10:33:31.893367 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:33:31.893412 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:33:31.893419 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:33:31.893452 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="DeleteError: failed to delete machine \"miyadav-jpfdm-worker-westus-mwnhx\": failed to delete machine: compute.VirtualMachinesDeleteFuture: asynchronous operation has not completed" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"82010"} "reason"="FailedDelete" I0424 10:33:32.536596 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:32.536625 1 controller.go:307] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent create I0424 10:33:32.536631 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:33.521830 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:33:33.566354 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:33.566393 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:33.566400 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:33:33.582424 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-rdl6b"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile W0424 10:33:33.582446 1 controller.go:309] miyadav-jpfdm-worker-westus-rdl6b: failed to create machine: requeue in: 20s I0424 10:33:33.582457 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:33:33.582494 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-rdl6b\"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81693"} "reason"="FailedCreate" I0424 10:33:51.348785 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:33:51.348815 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:33:51.689788 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:51.689814 1 controller.go:307] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent create I0424 10:33:51.689820 1 actuator.go:85] Creating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:33:52.879417 1 networkinterfaces.go:225] successfully created network interface miyadav-jpfdm-worker-westus-rdl6b-nic I0424 10:33:52.923770 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:52.923801 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:33:52.923806 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:33:52.940931 1 actuator.go:79] Machine error: failed to reconcile machine "miyadav-jpfdm-worker-westus-rdl6b"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile W0424 10:33:52.940955 1 controller.go:309] miyadav-jpfdm-worker-westus-rdl6b: failed to create machine: requeue in: 20s I0424 10:33:52.940967 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:33:52.941008 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:33:52.941020 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:33:52.941051 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="CreateError: failed to reconcile machine \"miyadav-jpfdm-worker-westus-rdl6b\"s: failed to create vm miyadav-jpfdm-worker-westus-rdl6b : vm miyadav-jpfdm-worker-westus-rdl6b is still in provisioning state Creating, reconcile" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81693"} "reason"="FailedCreate" I0424 10:33:52.948611 1 controller.go:332] Could not find node from noderef, it may have already been deleted: miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:52.948633 1 actuator.go:128] Deleting machine miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:52.949219 1 virtualmachines.go:225] deleting vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:53.287244 1 virtualmachines.go:242] successfully deleted vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:33:53.287268 1 disks.go:49] deleting disk miyadav-jpfdm-worker-westus-mwnhx_OSDisk I0424 10:33:53.611323 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:33:53.611440 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:33:53.611447 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-mwnhx: patching machine E0424 10:33:53.628982 1 actuator.go:79] Machine error: failed to delete machine "miyadav-jpfdm-worker-westus-mwnhx": failed to delete OS disk: result error: compute.DisksDeleteFuture: asynchronous operation has not completed E0424 10:33:53.629015 1 controller.go:224] miyadav-jpfdm-worker-westus-mwnhx: failed to delete machine: requeue in: 20s I0424 10:33:53.629024 1 controller.go:400] Actuator returned requeue-after error: requeue in: 20s I0424 10:33:53.629132 1 recorder.go:52] controller-runtime/manager/events "msg"="Warning" "message"="DeleteError: failed to delete machine \"miyadav-jpfdm-worker-westus-mwnhx\": failed to delete OS disk: result error: compute.DisksDeleteFuture: asynchronous operation has not completed" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"82010"} "reason"="FailedDelete" I0424 10:34:12.941205 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:34:12.941234 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:34:13.349545 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:34:13.349573 1 reconciler.go:372] Machine 87eb5dbb-df82-40d7-81c8-4de92bc59cb7 is running I0424 10:34:13.349584 1 controller.go:271] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent update I0424 10:34:13.349590 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:34:13.938421 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine E0424 10:34:13.965066 1 controller.go:278] miyadav-jpfdm-worker-westus-rdl6b: instance exists but providerID or addresses has not been given to the machine yet, requeuing I0424 10:34:13.965740 1 controller.go:163] miyadav-jpfdm-worker-westus-mwnhx: reconciling Machine I0424 10:34:13.965851 1 controller.go:203] miyadav-jpfdm-worker-westus-mwnhx: reconciling machine triggers delete I0424 10:34:13.965134 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Updated machine \"miyadav-jpfdm-worker-westus-rdl6b\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-rdl6b","uid":"ca5bf2e4-758f-486a-98d9-42de7920c493","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"81693"} "reason"="Updated" I0424 10:34:13.976395 1 controller.go:332] Could not find node from noderef, it may have already been deleted: miyadav-jpfdm-worker-westus-mwnhx I0424 10:34:13.976415 1 actuator.go:128] Deleting machine miyadav-jpfdm-worker-westus-mwnhx I0424 10:34:13.977145 1 virtualmachines.go:225] deleting vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:34:14.351822 1 virtualmachines.go:242] successfully deleted vm miyadav-jpfdm-worker-westus-mwnhx I0424 10:34:14.351845 1 disks.go:49] deleting disk miyadav-jpfdm-worker-westus-mwnhx_OSDisk I0424 10:34:14.429128 1 disks.go:65] successfully deleted disk miyadav-jpfdm-worker-westus-mwnhx_OSDisk I0424 10:34:14.429154 1 networkinterfaces.go:235] deleting nic miyadav-jpfdm-worker-westus-mwnhx-nic I0424 10:34:14.852371 1 networkinterfaces.go:254] successfully deleted nic miyadav-jpfdm-worker-westus-mwnhx-nic I0424 10:34:14.852438 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:34:14.852477 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-mwnhx: status unchanged I0424 10:34:14.852483 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-mwnhx: patching machine I0424 10:34:14.870521 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-mwnhx exists I0424 10:34:14.870597 1 recorder.go:52] controller-runtime/manager/events "msg"="Normal" "message"="Deleted machine \"miyadav-jpfdm-worker-westus-mwnhx\"" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-jpfdm-worker-westus-mwnhx","uid":"dee5926c-4624-4538-96a8-f5a7166e6d9a","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"82010"} "reason"="Deleted" I0424 10:34:15.097406 1 controller.go:241] miyadav-jpfdm-worker-westus-mwnhx: deleting node "miyadav-jpfdm-worker-westus-mwnhx" for machine I0424 10:34:15.097448 1 controller.go:388] Node "miyadav-jpfdm-worker-westus-mwnhx" not found I0424 10:34:15.118347 1 controller.go:255] miyadav-jpfdm-worker-westus-mwnhx: machine deletion successful I0424 10:34:15.118389 1 controller.go:282] controller-runtime/controller "msg"="Successfully Reconciled" "controller"="machine_controller" "request"={"Namespace":"openshift-machine-api","Name":"miyadav-jpfdm-worker-westus-mwnhx"} I0424 10:34:15.118427 1 controller.go:163] miyadav-jpfdm-worker-westus-rdl6b: reconciling Machine I0424 10:34:15.118436 1 actuator.go:196] Checking if machine miyadav-jpfdm-worker-westus-rdl6b exists I0424 10:34:15.429508 1 reconciler.go:352] Found vm for machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:34:15.429532 1 reconciler.go:372] Machine 87eb5dbb-df82-40d7-81c8-4de92bc59cb7 is running I0424 10:34:15.429543 1 controller.go:271] miyadav-jpfdm-worker-westus-rdl6b: reconciling machine triggers idempotent update I0424 10:34:15.429549 1 actuator.go:163] Updating machine miyadav-jpfdm-worker-westus-rdl6b I0424 10:34:15.802096 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:34:15.802135 1 machine_scope.go:169] miyadav-jpfdm-worker-westus-rdl6b: status unchanged I0424 10:34:15.802140 1 machine_scope.go:185] miyadav-jpfdm-worker-westus-rdl6b: patching machine I0424 10:34:15.820369 1 controller.go:419] miyadav-jpfdm-worker-westus-rdl6b: going into phase "Provisioned"
It did not got stuck into "failed" status this time .. #9
Let's consider the "failed" status a transient thing and leave it aside. To get to the path that originated this BZ, the node needs to go unreachable. Once you have a running cluster, can you please: 1 - Enforce a node to go unreachable. E.g killing the kubelet or in AWS you can just stop the instance in the console. 2 - Delete the machine backing the unreachable node via kubectl delete 3 - Share your steps with the name of the machine deleted and attach a file with machine controller logs here
Thanks Alberto , followed the steps on #11 but on Azure NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.5.0-0.nightly-2020-04-21-103613 True False 25m Cluster version is 4.5.0-0.nightly-2020-04-21-103613 Reproducible Always. Steps to Reproduce: 1.Stopped the machine from Iaas console , to make the kubelet die . Instance stopped successfully 2. Delete a machine oc delete machine <machine-name that was stopped from Iaas> Machine terminated successfully 3. oc logs -f machine-api-controllers-788f58b4-jl9bj -c machine-controller Actual & Expected logs : [miyadav@miyadav bug1804635]$ oc logs machine-api-controllers-788f58b4-jl9bj -c machine-controller | grep "draining will wait" I0424 12:08:31.625026 1 controller.go:361] "miyadav-jpfdm-worker-westus-rdl6b": Node "miyadav-jpfdm-worker-westus-rdl6b" is unreachable, draining will wait 300 seconds after pod is signalled for deletion and skip after it I0424 12:08:32.502973 1 controller.go:361] "miyadav-jpfdm-worker-westus-rdl6b": Node "miyadav-jpfdm-worker-westus-rdl6b" is unreachable, draining will wait 300 seconds after pod is signalled for deletion and skip after it I0424 12:08:52.481719 1 controller.go:361] "miyadav-jpfdm-worker-westus-rdl6b": Node "miyadav-jpfdm-worker-westus-rdl6b" is unreachable, draining will wait 300 seconds after pod is signalled for deletion and skip after it [miyadav@miyadav bug1804635]$ Additional info : Here is the pastebin since you asked for full logs . http://pastebin.test.redhat.com/858849
Moved to VERIFIED
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 (OpenShift Container Platform 4.5 image release 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-2020:2409