Bug 2094335 - [Nutanix] - debug logs are enabled by default in machine-controller
Summary: [Nutanix] - debug logs are enabled by default in machine-controller
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: OpenShift Container Platform
Classification: Red Hat
Component: Cloud Compute
Version: 4.11
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: 4.11.0
Assignee: Yanhua Li
QA Contact: Milind Yadav
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2022-06-07 12:19 UTC by Milind Yadav
Modified: 2023-09-15 01:55 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-08-10 11:16:50 UTC
Target Upstream Version:
Embargoed:

Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github openshift machine-api-provider-nutanix pull 19 0 None open Bug 2094335: [Nutanix] - debug log should not be enabled by default 2022-06-22 11:22:30 UTC
Red Hat Product Errata RHSA-2022:5069 0 None None None 2022-08-10 11:16:59 UTC

Description Milind Yadav 2022-06-07 12:19:28 UTC 
Description of problem:Seems like debug log is enabled by default for machine-controller pods 


Version-Release number of selected component (if applicable):
4.11.0-0.nightly-2022-06-06-025509

How reproducible:
Always

Steps to Reproduce:
1.scale machineset  
[miyadav@miyadav nutanix]$ oc get machineset 
NAME                     DESIRED   CURRENT   READY   AVAILABLE   AGE
huliu-n13-sz54h-1        1         1         1       1           7h16m
huliu-n13-sz54h-worker   2         2         2       2           9h
[miyadav@miyadav nutanix]$ oc scale machineset huliu-n13-sz54h-worker --replicas 3 
machineset.machine.openshift.io/huliu-n13-sz54h-worker scaled



Expected and actual 
Machineset scaled successfully 

2.Monitor machinecontroller logs 

.
.
.
.
2022/06/07 12:13:17 [DEBUG] GET /api/nutanix/v3/vms/23b8a5b4-b133-41a1-985e-099a1f319677 HTTP/1.1
Host: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440
Accept: application/json
Authorization: Basic c2dhbzpqP1MzdHomeA==
Content-Type: application/json
User-Agent: nutanix/v3


2022/06/07 12:13:17 [DEBUG] HTTP/1.1 200 OK
Transfer-Encoding: chunked
Content-Security-Policy: default-src 'self' https://*.nutanix.com; script-src 'self' 'unsafe-inline' 'unsafe-eval'; style-src 'self' 'unsafe-inline'; connect-src 'self' wss: https://downloads.frame.nutanix.com https://downloads.frame.nutanix.us; img-src 'self' blob: data:; frame-src 'self' https://*.nutanix.com blob: data:
Content-Type: application/json
Date: Tue, 07 Jun 2022 12:13:17 GMT
Server: envoy
Set-Cookie: NTNX_IGW_SESSION=eyJ0eXAiOiJKV1QiLCJhbGciOiJSUzI1NiJ9.eyJ1c2VyX3Byb2ZpbGUiOiJ7XCJ1c2VybmFtZVwiOiBcInNnYW9cIiwgXCJkb21haW5cIjogbnVsbCwgXCJsZWdhY3lfYWRtaW5fYXV0aG9yaXRpZXNcIjogW1wiUk9MRV9DTFVTVEVSX0FETUlOXCIsIFwiUk9MRV9DTFVTVEVSX1ZJRVdFUlwiLCBcIlJPTEVfTVVMVElDTFVTVEVSX0FETUlOXCJdLCBcImF1dGhlbnRpY2F0ZWRcIjogdHJ1ZSwgXCJfcGVybWFuZW50XCI6IHRydWUsIFwicm9sZXNcIjogW1wiUHJpc20gQWRtaW5cIiwgXCJQcmlzbSBWaWV3ZXJcIl0sIFwibG9nX3V1aWRcIjogXCIyMTYyZTg3Ny1jZmEyLTRlMTQtOGFjNi0xNjNiNzNlMmE5ODRcIiwgXCJ1c2VydHlwZVwiOiBcImxvY2FsXCIsIFwiYXBwX2RhdGFcIjoge30sIFwiYXV0aF9pbmZvXCI6IHtcInVzZXJuYW1lXCI6IFwic2dhb1wiLCBcInJlbW90ZV9hdXRob3JpemF0aW9uXCI6IG51bGwsIFwidXNlcl9ncm91cF91dWlkc1wiOiBudWxsLCBcInJlbW90ZV9hdXRoX2pzb25cIjogbnVsbCwgXCJzZXJ2aWNlX25hbWVcIjogbnVsbCwgXCJ0b2tlbl9hdWRpZW5jZVwiOiBudWxsLCBcInRva2VuX2lzc3VlclwiOiBudWxsLCBcInVzZXJfdXVpZFwiOiBcIjYyZjExNjk4LTk3ZTQtNTFiMy04OTkyLTUyNTllM2NjMzNjNlwiLCBcInRlbmFudF91dWlkXCI6IFwiMDAwMDAwMDAtMDAwMC0wMDAwLTAwMDAtMDAwMDAwMDAwMDAwXCJ9fSIsImp0aSI6IjdjYWQzMzExLWQxNDgtMzUwZi1hZTFjLWQ5ZjZmNDU2NWFlZiIsImlzcyI6IkF0aGVuYSIsImlhdCI6MTY1NDYwMzk5NywiZXhwIjoxNjU0NjA0ODk3fQ.Eriz3bu4X6jLcjhV0-EpHhz6_5CgSM1qM2zXW7o_1mwnXVaBGayX15UyP19v3hFWd3J5duJMlKP2StuyOq40mImjHu5XlLwj07obZfhUTdYg6DReUcD_VEWcZHwecatIffWJ9mxoH4JCETx9CcPo-Xtyr2mzMmKWhPsCC0ikC822_xHZ9ZIVzY07KA0Nk1a2Huq_AZoIqXaoe0q6_asM8cEYdxNZ1_c-dzsssJmU49dz2SQtmduPX6n7kJXhT3G4buN0e3CH2-toZDTnkIuYaw_md35OjGxQ0sUBPIEifydxphe6mMgSqdz0Ilu6OrAOmI7ImXWm3RPww7QyT_0YbA; Expires=Tue, 07-Jun-2022 12:28:17 GMT; HttpOnly; Path=/; SameSite=Lax
Strict-Transport-Security: max-age=8640000:includeSubdomains
Vary: Accept-Encoding
X-Content-Type-Options: nosniff
X-Dns-Prefetch-Control: off
X-Envoy-Upstream-Service-Time: 307
X-Frame-Options: SAMEORIGIN
X-Ntnx-Env: pc
X-Ntnx-Product: pc.2022.1
X-Permitted-Cross-Domain-Policies: master-only
X-Xss-Protection: 1; mode=block
.
.
.

Expected :
Info logs should be present 

Actual :
Too much logging info being pushed seems debug log is on for machine-controller 


Additional info:

this is not happening for other containers like machine-heathcheck-controller , nodelink-controller and others .
Comment 1 Sid Shukla 2022-06-13 13:19:58 UTC 
Can you add some more info?
Comment 2 Milind Yadav 2022-06-14 02:59:20 UTC 
@Sid , let me know are the comments marked as private not visible to you ? I changed it now , Please confirm if that was the case or you want any other info ?
Comment 3 Sid Shukla 2022-06-14 11:57:25 UTC 
@Milind; thanks! the comment is visible now.
Comment 4 Joel Speed 2022-06-16 13:10:31 UTC 
@yanhli Could you please take a look at this bug?
Comment 7 Milind Yadav 2022-06-23 10:25:36 UTC 
Validated on - [miyadav@miyadav nutanix]$ oc get clusterversion 
NAME      VERSION                              AVAILABLE   PROGRESSING   SINCE   STATUS
version   4.11.0-0.nightly-2022-06-22-235234   True        False         33m     Cluster version is 4.11.0-0.nightly-2022-06-22-235234





Followed same steps as mentioned in comment#1 , debug logs not seen as default logs : 
After scaling machineset 

[miyadav@miyadav nutanix]$ oc log -f machine-api-controllers-7879d9c49-lx94h -c machine-controller 

.
.
.
.
.
I0623 10:15:48.784514       1 actuator.go:114] miyadav-2306nu-xnx5w-worker-77frw: actuator checking if machine exists
I0623 10:15:48.784665       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:15:48.784677       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:15:48.784687       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:15:48.992834       1 reconciler.go:228] miyadav-2306nu-xnx5w-worker-77frw: vm exists
I0623 10:15:48.992922       1 controller.go:305] miyadav-2306nu-xnx5w-worker-77frw: reconciling machine triggers idempotent update
I0623 10:15:48.992950       1 actuator.go:130] miyadav-2306nu-xnx5w-worker-77frw: actuator updating machine
I0623 10:15:48.993076       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:15:48.993107       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:15:48.993136       1 reconciler.go:80] miyadav-2306nu-xnx5w-worker-77frw: updating machine
I0623 10:15:48.993165       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:15:49.177449       1 reconciler.go:306] miyadav-2306nu-xnx5w-worker-77frw: updating machine providerID
I0623 10:15:49.177483       1 reconciler.go:264] miyadav-2306nu-xnx5w-worker-77frw: ProviderID already set in the machine Spec with value: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:15:49.185905       1 reconciler.go:295] miyadav-2306nu-xnx5w-worker-77frw: The node "miyadav-2306nu-xnx5w-worker-77frw" spec.providerID is set to: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:15:49.185987       1 reconciler.go:320] miyadav-2306nu-xnx5w-worker-77frw: updated machine instance state annotations (machine.openshift.io/instance-type: AHV), (machine.openshift.io/instance-state: COMPLETE), (machine.openshift.io/instance-power-state: ON)
I0623 10:15:49.186016       1 machine_scope.go:211] miyadav-2306nu-xnx5w-worker-77frw: Updating providerStatus
I0623 10:15:49.186044       1 reconciler.go:135] miyadav-2306nu-xnx5w-worker-77frw: updated machine vm state
I0623 10:15:49.186070       1 machine_scope.go:154] miyadav-2306nu-xnx5w-worker-77frw: patching machine
I0623 10:15:49.209421       1 controller.go:426] miyadav-2306nu-xnx5w-worker-77frw: going into phase "Running"
I0623 10:15:49.209526       1 logr.go:252] events "msg"="Normal"  "message"="Updated Machine miyadav-2306nu-xnx5w-worker-77frw" "object"={"kind":"Machine","namespace":"openshift-machine-api","name":"miyadav-2306nu-xnx5w-worker-77frw","uid":"1336716a-597c-47b9-a671-c90b4d159b85","apiVersion":"machine.openshift.io/v1beta1","resourceVersion":"43570"} "reason"="Update"
I0623 10:15:49.217212       1 controller.go:179] miyadav-2306nu-xnx5w-worker-77frw: reconciling Machine
I0623 10:15:49.217229       1 actuator.go:114] miyadav-2306nu-xnx5w-worker-77frw: actuator checking if machine exists
I0623 10:15:49.217296       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:15:49.217305       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:15:49.217313       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:15:49.400622       1 reconciler.go:228] miyadav-2306nu-xnx5w-worker-77frw: vm exists
I0623 10:15:49.400642       1 controller.go:305] miyadav-2306nu-xnx5w-worker-77frw: reconciling machine triggers idempotent update
I0623 10:15:49.400647       1 actuator.go:130] miyadav-2306nu-xnx5w-worker-77frw: actuator updating machine
I0623 10:15:49.400737       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:15:49.400748       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:15:49.400763       1 reconciler.go:80] miyadav-2306nu-xnx5w-worker-77frw: updating machine
I0623 10:15:49.400767       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:15:49.583315       1 reconciler.go:306] miyadav-2306nu-xnx5w-worker-77frw: updating machine providerID
I0623 10:15:49.583410       1 reconciler.go:264] miyadav-2306nu-xnx5w-worker-77frw: ProviderID already set in the machine Spec with value: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:15:49.583466       1 reconciler.go:287] miyadav-2306nu-xnx5w-worker-77frw: The node "miyadav-2306nu-xnx5w-worker-77frw" spec.providerID is already set with value: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:15:49.583494       1 reconciler.go:320] miyadav-2306nu-xnx5w-worker-77frw: updated machine instance state annotations (machine.openshift.io/instance-type: AHV), (machine.openshift.io/instance-state: COMPLETE), (machine.openshift.io/instance-power-state: ON)
I0623 10:15:49.583519       1 machine_scope.go:211] miyadav-2306nu-xnx5w-worker-77frw: Updating providerStatus
I0623 10:15:49.583564       1 reconciler.go:135] miyadav-2306nu-xnx5w-worker-77frw: updated machine vm state
I0623 10:15:49.583596       1 machine_scope.go:154] miyadav-2306nu-xnx5w-worker-77frw: patching machine
I0623 10:16:19.519533       1 controller.go:179] miyadav-2306nu-xnx5w-worker-77frw: reconciling Machine
I0623 10:16:19.521004       1 actuator.go:114] miyadav-2306nu-xnx5w-worker-77frw: actuator checking if machine exists
I0623 10:16:19.521480       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:16:19.521668       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:16:19.521728       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:16:19.535688       1 controller.go:57] controllers/MachineSet "msg"="Reconciling" "machineset"="miyadav-2306nu-xnx5w-worker" "namespace"="openshift-machine-api" 
I0623 10:16:19.694118       1 reconciler.go:228] miyadav-2306nu-xnx5w-worker-77frw: vm exists
I0623 10:16:19.694228       1 controller.go:305] miyadav-2306nu-xnx5w-worker-77frw: reconciling machine triggers idempotent update
I0623 10:16:19.694483       1 actuator.go:130] miyadav-2306nu-xnx5w-worker-77frw: actuator updating machine
I0623 10:16:19.694681       1 utils.go:186] Successfully set the PrismCentral credentials to the clientOptions to create the Prism Central client.
I0623 10:16:19.694743       1 client.go:55] To create nutanixClient with creds: (url: prismcentral.lts-cluster.nutanix-dev.devcluster.openshift.com:9440, insecure: false, debug-log: false)
I0623 10:16:19.694777       1 reconciler.go:80] miyadav-2306nu-xnx5w-worker-77frw: updating machine
I0623 10:16:19.694840       1 vm.go:301] Checking if VM with UUID b9bb7e9a-de2f-41de-a024-0acb3d06a328 exists.
I0623 10:16:19.866328       1 reconciler.go:306] miyadav-2306nu-xnx5w-worker-77frw: updating machine providerID
I0623 10:16:19.866353       1 reconciler.go:264] miyadav-2306nu-xnx5w-worker-77frw: ProviderID already set in the machine Spec with value: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:16:19.866397       1 reconciler.go:287] miyadav-2306nu-xnx5w-worker-77frw: The node "miyadav-2306nu-xnx5w-worker-77frw" spec.providerID is already set with value: nutanix://b9bb7e9a-de2f-41de-a024-0acb3d06a328
I0623 10:16:19.866407       1 reconciler.go:320] miyadav-2306nu-xnx5w-worker-77frw: updated machine instance state annotations (machine.openshift.io/instance-type: AHV), (machine.openshift.io/instance-state: COMPLETE), (machine.openshift.io/instance-power-state: ON)
I0623 10:16:19.866414       1 machine_scope.go:211] miyadav-2306nu-xnx5w-worker-77frw: Updating providerStatus
I0623 10:16:19.866422       1 reconciler.go:135] miyadav-2306nu-xnx5w-worker-77frw: updated machine vm state
.
.
.
.


Additional info:
Moved to VERIFIED
Comment 9 errata-xmlrpc 2022-08-10 11:16:50 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 (Important: OpenShift Container Platform 4.11.0 bug fix and security update), 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/RHSA-2022:5069
Comment 10 Red Hat Bugzilla 2023-09-15 01:55:37 UTC 
The needinfo request[s] on this closed bug have been removed as they have been unresolved for 365 days
Note You need to log in before you can comment on or make changes to this bug.