Hide Forgot
Description of problem: Current logging in the machineset controller using klog does not work Version-Release number of selected component (if applicable): $ oc get clusterversion NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.0.0-9 True False 35s Cluster version is 4.0.0-9 How reproducible: Always Steps to Reproduce: 1. Create a new machine 2. Check machine-controller logs if no event is triggered no reconciling logs 3. Actual results: When creating a new machine no reconciling logs. $ oc logs -f clusterapi-manager-controllers-5b4996fb88-bzst7 -c machine-controller I0111 05:30:50.471472 1 actuator.go:353] checking if machine exists I0111 05:30:50.475524 1 utils.go:151] Falling to providerConfig I0111 05:30:50.532829 1 actuator.go:361] instance does not exist I0111 05:30:50.532888 1 actuator.go:109] creating machine I0111 05:30:50.532899 1 utils.go:151] Falling to providerConfig I0111 05:30:50.558408 1 instances.go:44] no stopped instances found for machine zhsun-worker-us-east-2a I0111 05:30:50.575114 1 instances.go:131] Using AMI ami-085b89e82b74a76b5 I0111 05:30:50.575200 1 instances.go:73] Describing security groups based on filters I0111 05:30:51.046444 1 instances.go:108] Describing subnets based on filters I0111 05:30:52.087296 1 actuator.go:450] updating status I0111 05:30:52.088099 1 actuator.go:494] finished calculating AWS status I0111 05:30:52.088313 1 actuator.go:143] machine status has changed, updating I0111 05:30:52.101684 1 actuator.go:512] instance state still pending, returning an error to requeue I0111 05:30:52.105620 1 actuator.go:353] checking if machine exists I0111 05:30:52.105763 1 utils.go:151] Falling to providerConfig I0111 05:30:52.322515 1 actuator.go:366] instance exists as "i-056397970f9c56899" I0111 05:30:52.322617 1 actuator.go:283] updating machine I0111 05:30:52.322628 1 utils.go:151] Falling to providerConfig I0111 05:30:52.323170 1 actuator.go:291] obtaining EC2 client for region I0111 05:30:52.366060 1 actuator.go:307] found 1 instances for machine I0111 05:30:52.366086 1 actuator.go:325] instance found I0111 05:30:52.366097 1 actuator.go:450] updating status I0111 05:30:52.366217 1 actuator.go:494] finished calculating AWS status I0111 05:30:52.366395 1 actuator.go:152] status unchanged Expected results: When creating a new machine, machine-controller output reconciling logs like bellow. If no event is triggered no reconciling logs. 1105 09:34:31.090049 1 controller.go:113] Running reconcile Machine for aws-actuator-testing-machine I1105 09:34:31.090151 1 actuator.go:548] checking if machine exists I1105 09:34:31.171290 1 actuator.go:556] instance does not exist I1105 09:34:31.171454 1 controller.go:175] Reconciling machine object aws-actuator-testing-machine triggers idempotent create. I1105 09:34:31.171603 1 actuator.go:110] creating machine I1105 09:34:31.180079 1 actuator.go:299] Using AMI ami-2fb42b39 W1105 09:34:31.180238 1 actuator.go:345] More than one subnet id returned, only first one will be used I1105 09:34:32.405188 1 actuator.go:630] updating status I1105 09:34:32.405444 1 actuator.go:673] finished calculating AWS status I1105 09:34:32.405793 1 actuator.go:142] machine status has changed, updating I1105 09:34:32.429694 1 actuator.go:692] instance state still pending, returning an error to requeue W1105 09:34:32.429796 1 controller.go:177] unable to create machine aws-actuator-testing-machine: requeue in: 20s I1105 09:34:32.429849 1 controller.go:179] Actuator returned requeue-after error: requeue in: 20s I1105 09:34:32.429968 1 controller.go:113] Running reconcile Machine for aws-actuator-testing-machine I1105 09:34:32.430060 1 actuator.go:548] checking if machine exists I1105 09:34:32.682006 1 actuator.go:561] instance exists as "i-036cbba76762d1ffc" I1105 09:34:32.682121 1 controller.go:163] Reconciling machine object aws-actuator-testing-machine triggers idempotent update. I1105 09:34:32.682397 1 actuator.go:483] updating machine I1105 09:34:32.683078 1 actuator.go:492] obtaining EC2 client for region I1105 09:34:32.761475 1 actuator.go:508] found 1 instances for machine I1105 09:34:32.761514 1 actuator.go:526] instance found I1105 09:34:32.761531 1 actuator.go:630] updating status I1105 09:34:32.761616 1 actuator.go:673] finished calculating AWS status I1105 09:34:32.761791 1 actuator.go:151] status unchanged I1105 09:34:32.761808 1 actuator.go:692] instance state still pending, returning an error to requeue I1105 09:34:32.761822 1 controller.go:167] Actuator returned requeue-after error: requeue in: 20s Additional info:
Downstream PR: https://github.com/openshift/cluster-api-provider-aws/pull/141
Upstream PR: https://github.com/kubernetes-sigs/cluster-api/pull/677
Verified. $ oc get clusterversion NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.0.0-0.nightly-2019-01-17-185315 True False 1h Cluster version is 4.0.0-0.nightly-2019-01-17-185315 Create a new machine, check logs. $ oc logs -f clusterapi-manager-controllers-64584db79-d2hq5 -c machine-controller I0118 07:09:43.902388 1 controller.go:113] Running reconcile Machine for zhsun-worker-us-east-2a I0118 07:09:43.907973 1 actuator.go:401] checking if machine exists I0118 07:09:43.956277 1 actuator.go:409] instance does not exist I0118 07:09:43.961396 1 controller.go:181] Reconciling machine object zhsun-worker-us-east-2a triggers idempotent create. I0118 07:09:43.961504 1 actuator.go:110] creating machine I0118 07:09:43.983946 1 instances.go:44] no stopped instances found for machine zhsun-worker-us-east-2a I0118 07:09:43.988827 1 instances.go:141] Using AMI ami-085b89e82b74a76b5 I0118 07:09:43.988926 1 instances.go:73] Describing security groups based on filters I0118 07:09:44.069888 1 instances.go:118] Describing subnets based on filters I0118 07:09:44.877535 1 actuator.go:498] updating status I0118 07:09:44.877665 1 actuator.go:542] finished calculating AWS status I0118 07:09:44.877794 1 actuator.go:144] machine status has changed, updating I0118 07:09:44.887182 1 actuator.go:560] instance state still pending, returning an error to requeue W0118 07:09:44.887205 1 controller.go:183] unable to create machine zhsun-worker-us-east-2a: requeue in: 20s I0118 07:09:44.887225 1 controller.go:185] Actuator returned requeue-after error: requeue in: 20s I0118 07:09:44.887584 1 controller.go:113] Running reconcile Machine for zhsun-worker-us-east-2a I0118 07:09:44.887618 1 actuator.go:401] checking if machine exists I0118 07:09:45.080442 1 actuator.go:414] instance exists as "i-06ff9bddbb6ea21ca" I0118 07:09:45.080475 1 controller.go:170] Reconciling machine object zhsun-worker-us-east-2a triggers idempotent update. I0118 07:09:45.080518 1 actuator.go:331] updating machine I0118 07:09:45.080630 1 actuator.go:339] obtaining EC2 client for region I0118 07:09:45.119829 1 actuator.go:355] found 1 instances for machine I0118 07:09:45.124140 1 actuator.go:373] instance found I0118 07:09:45.124159 1 actuator.go:498] updating status I0118 07:09:45.124255 1 actuator.go:542] finished calculating AWS status I0118 07:09:45.124387 1 actuator.go:153] status unchanged I0118 07:09:45.124399 1 actuator.go:560] instance state still pending, returning an error to requeue I0118 07:09:45.124413 1 controller.go:173] Actuator returned requeue-after error: requeue in: 20s I0118 07:10:04.887503 1 controller.go:113] Running reconcile Machine for zhsun-worker-us-east-2a I0118 07:10:04.887568 1 actuator.go:401] checking if machine exists I0118 07:10:05.011314 1 actuator.go:414] instance exists as "i-06ff9bddbb6ea21ca" I0118 07:10:05.011348 1 controller.go:170] Reconciling machine object zhsun-worker-us-east-2a triggers idempotent update. I0118 07:10:05.011395 1 actuator.go:331] updating machine I0118 07:10:05.011503 1 actuator.go:339] obtaining EC2 client for region I0118 07:10:05.052654 1 actuator.go:355] found 1 instances for machine I0118 07:10:05.052681 1 actuator.go:373] instance found I0118 07:10:05.052692 1 actuator.go:498] updating status I0118 07:10:05.052767 1 actuator.go:542] finished calculating AWS status I0118 07:10:05.052926 1 actuator.go:144] machine status has changed, updating I0118 07:10:05.061950 1 controller.go:113] Running reconcile Machine for zhsun-worker-us-east-2a I0118 07:10:05.062068 1 actuator.go:401] checking if machine exists I0118 07:10:05.096972 1 actuator.go:414] instance exists as "i-06ff9bddbb6ea21ca" I0118 07:10:05.096998 1 controller.go:170] Reconciling machine object zhsun-worker-us-east-2a triggers idempotent update. I0118 07:10:05.097028 1 actuator.go:331] updating machine I0118 07:10:05.097114 1 actuator.go:339] obtaining EC2 client for region I0118 07:10:05.139602 1 actuator.go:355] found 1 instances for machine I0118 07:10:05.139716 1 actuator.go:373] instance found I0118 07:10:05.139782 1 actuator.go:498] updating status I0118 07:10:05.139919 1 actuator.go:542] finished calculating AWS status I0118 07:10:05.140046 1 actuator.go:153] status unchanged
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:0758