Bug 2083256 - SSP Reconcile logging improvement when CR resources are changed
Summary: SSP Reconcile logging improvement when CR resources are changed
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Container Native Virtualization (CNV)
Classification: Red Hat
Component: SSP
Version: 4.11.0
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
: 4.11.0
Assignee: Andrej Krejcir
QA Contact: Geetika Kapoor
URL:
Whiteboard:
Depends On:
Blocks: 2089658
TreeView+ depends on / blocked
 
Reported: 2022-05-09 14:50 UTC by Geetika Kapoor
Modified: 2022-09-14 19:32 UTC (History)
4 users (show)

Fixed In Version: kubevirt-ssp-operator-container-v4.11.0-36
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 2089658 (view as bug list)
Environment:
Last Closed: 2022-09-14 19:32:24 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github kubevirt ssp-operator pull 351 0 None open Log the reason why reconciliation is triggered 2022-05-13 12:25:59 UTC
Red Hat Issue Tracker CNV-18061 0 None None None 2022-05-13 11:34:22 UTC

Description Geetika Kapoor 2022-05-09 14:50:16 UTC
Description of problem:

Better logging is needed for SSP 'ssps.ssp.kubevirt.io' in case SSP reconcile. Current logger don't show why reconcile happens and what changes in CR.
Changes which let reconcile to happen is good to have and it will help to identify product issues and if reconcile should actually happen.

Current logs:

{"level":"info","ts":1652102869.4633186,"logger":"controller.ssp","msg":"Starting workers","reconciler group":"ssp.kubevirt.io","reconciler kind":"SSP","worker count":1}
{"level":"info","ts":1652102869.4998937,"logger":"ssp-resource","msg":"validate update","name":"ssp-kubevirt-hyperconverged"}
{"level":"error","ts":1652102870.4478307,"logger":"controller.ssp","msg":"Reconciler error","reconciler group":"ssp.kubevirt.io","reconciler kind":"SSP","name":"ssp-kubevirt-hyperconverged","namespace":"openshift-cnv","error":"Operation cannot be fulfilled on ssps.ssp.kubevirt.io \"ssp-kubevirt-hyperconverged\": the object has been modified; please apply your changes to the latest version and try again","stacktrace":"sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\t/remote-source/app/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:266\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2\n\t/remote-source/app/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:227"}

Version-Release number of selected component (if applicable):
4.10.1

How reproducible:
always. Devops team is seeing most of the times

Steps to Reproduce:
1. Running automation tests show these errors
2.
3.

Actual results:


Expected results:


Additional info:

Comment 3 Andrej Krejcir 2022-05-10 07:10:05 UTC
We set the default log level to "info", because "debug" was too verbose: Bug 2037421

The "debug" level can be enabled using the command line parameter "--zap-log-level debug" in the ssp operator deployment.
But probably HCO or OLM will revert this change.

Comment 4 Geetika Kapoor 2022-06-30 17:07:21 UTC
$ oc get csv -n openshift-cnv
NAME                                       DISPLAY                                          VERSION                 REPLACES                                   PHASE
jaeger-operator.v1.30.1-0.1648511826.p     Red Hat OpenShift distributed tracing platform   1.30.1+0.1648511826.p                                              Succeeded
kiali-operator.v1.48.0                     Kiali Operator                                   1.48.0                  kiali-operator.v1.36.10                    Succeeded
kubevirt-hyperconverged-operator.v4.11.0   OpenShift Virtualization                         4.11.0                  kubevirt-hyperconverged-operator.v4.10.2   Succeeded
servicemeshoperator.v2.2.0                 Red Hat OpenShift Service Mesh                   2.2.0-0                 servicemeshoperator.v2.1.3                 Succeeded

Logging shows extra logging messages

{"level":"info","ts":1656603209.7133174,"logger":"controllers.SSP","msg":"Reconciliation event received","ssp":{"namespace":"openshift-cnv","name":"ssp-kubevirt-hyperconverged"},"cause_type":"DataImportCron","cause_object":"openshift-virtualization-os-images/dic-non-existing-source"}
{"level":"info","ts":1656603209.7133625,"logger":"controllers.SSP","msg":"Starting reconciliation","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603209.723232,"logger":"controllers.SSP","msg":"Reconciling operands...","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603210.7501254,"logger":"controllers.SSP","msg":"CR status updated","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603249.705958,"logger":"controllers.SSP","msg":"Reconciliation event received","ssp":{"namespace":"openshift-cnv","name":"ssp-kubevirt-hyperconverged"},"cause_type":"DataImportCron","cause_object":"openshift-virtualization-os-images/dic-non-existing-source"}
{"level":"info","ts":1656603249.7060814,"logger":"controllers.SSP","msg":"Reconciliation event received","ssp":{"namespace":"openshift-cnv","name":"ssp-kubevirt-hyperconverged"},"cause_type":"DataImportCron","cause_object":"openshift-virtualization-os-images/dic-non-existing-source"}
{"level":"info","ts":1656603249.7061138,"logger":"controllers.SSP","msg":"Starting reconciliation","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603249.717128,"logger":"controllers.SSP","msg":"Reconciling operands...","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603250.589064,"logger":"controllers.SSP","msg":"CR status updated","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603257.9466932,"logger":"ssp-resource","msg":"validate update","name":"ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603257.9694862,"logger":"ssp-resource","msg":"validate update","name":"ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603257.973504,"logger":"controllers.SSP","msg":"Starting reconciliation","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}
{"level":"info","ts":1656603257.9816644,"logger":"controllers.SSP","msg":"Reconciling operands...","ssp":"openshift-cnv/ssp-kubevirt-hyperconverged"}

Comment 7 errata-xmlrpc 2022-09-14 19:32:24 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 Virtualization 4.11.0 Images security and bug fix 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:6526


Note You need to log in before you can comment on or make changes to this bug.