Uploaded image for project: 'OpenShift Bugs'
  1. OpenShift Bugs
  2. OCPBUGS-4054

cluster-ingress-operator's configurable-route controller's startup is noisy

XMLWordPrintable

    • Low
    • None
    • 2
    • Sprint 228
    • 1
    • Rejected
    • False
    • Hide

      None

      Show
      None
    • Hide
      Cause: The Ingress Operator configures one of its watches in a needlessly complicated way.

      Consequence: When the Ingress Operator starts, it logs unnecessarily verbose log messages about "Starting EventSource" for the "configurable_route_controller". For example:

          Starting EventSource {"controller": "configurable_route_controller", "source": "&{{%!s(*v1.Role=&{{ } { 0 {{0 0 <nil>}} <nil> <nil> map[] map[] [] [] []} []}) %!s(*cache.multiNamespaceCache=&{map[openshift-config:0xc000712110 openshift-config-managed:0xc000712108 openshift-ingress:0xc0007120f8 openshift-ingress-canary:0xc000712100 openshift-ingress-operator:0xc0007120e8] 0xc000261ea0 0xc00010e190 0xc0007120e0}) %!s(chan error=<nil>) %!s(func()=<nil>)}}"}

      Fix: The relevant watch initialization has been simplified.

      Result: The Ingress Operator logs are less noisy. For example:

          Starting EventSource {"controller": "configurable_route_controller", "source": "kind source: *v1.Role"}
      Show
      Cause: The Ingress Operator configures one of its watches in a needlessly complicated way. Consequence: When the Ingress Operator starts, it logs unnecessarily verbose log messages about "Starting EventSource" for the "configurable_route_controller". For example:     Starting EventSource {"controller": "configurable_route_controller", "source": "&{{%!s(*v1.Role=&{{ } { 0 {{0 0 <nil>}} <nil> <nil> map[] map[] [] [] []} []}) %!s(*cache.multiNamespaceCache=&{map[openshift-config:0xc000712110 openshift-config-managed:0xc000712108 openshift-ingress:0xc0007120f8 openshift-ingress-canary:0xc000712100 openshift-ingress-operator:0xc0007120e8] 0xc000261ea0 0xc00010e190 0xc0007120e0}) %!s(chan error=<nil>) %!s(func()=<nil>)}}"} Fix: The relevant watch initialization has been simplified. Result: The Ingress Operator logs are less noisy. For example:     Starting EventSource {"controller": "configurable_route_controller", "source": "kind source: *v1.Role"}
    • Bug Fix

      Description of problem:

      The cluster-ingress-operator log output is a little noisy when starting the operator's controllers, in part because of the way in which the configurable-route controller configures its watches.

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

      4.10+.

      How reproducible:

      Always.

      Steps to Reproduce:

      1. Check the ingress-operator logs, and search for "configurable_route_controller": oc -n openshift-ingress-operator logs -c ingress-operator deploy/ingress-operator | grep -e configurable_route_controller

      Actual results:

      The operator emits log messages like the following on startup:

      2022-11-23T08:47:35.646-0600    INFO    operator.init   controller/controller.go:241    Starting EventSource    {"controller": "configurable_route_controller", "source": "&{{%!s(*v1.Role=&{{ } {      0 {{0 0 <nil>}} <nil> <nil> map[] map[] [] [] []} []}) %!s(*cache.multiNamespaceCache=&{map[openshift-config:0xc000712110 openshift-config-managed:0xc000712108 openshift-ingress:0xc0007120f8 openshift-ingress-canary:0xc000712100 openshift-ingress-operator:0xc0007120e8] 0xc000261ea0 0xc00010e190 0xc0007120e0}) %!s(chan error=<nil>) %!s(func()=<nil>)}}"}
      2022-11-23T08:47:35.646-0600    INFO    operator.init   controller/controller.go:241    Starting EventSource    {"controller": "configurable_route_controller", "source": "&{{%!s(*v1.RoleBinding=&{{ } {      0 {{0 0 <nil>}} <nil> <nil> map[] map[] [] [] []} [] {  }}) %!s(*cache.multiNamespaceCache=&{map[openshift-config:0xc000712110 openshift-config-managed:0xc000712108 openshift-ingress:0xc0007120f8 openshift-ingress-canary:0xc000712100 openshift-ingress-operator:0xc0007120e8] 0xc000261ea0 0xc00010e190 0xc0007120e0}) %!s(chan error=<nil>) %!s(func()=<nil>)}}"}
      2022-11-23T08:47:35.646-0600    INFO    operator.init   controller/controller.go:241    Starting Controller     {"controller": "configurable_route_controller"}
      

      Expected results:

      The operator should emit log messages like the following on startup:

      2022-11-23T08:48:43.076-0600    INFO    operator.init   controller/controller.go:241    Starting EventSource    {"controller": "configurable_route_controller", "source": "kind source: *v1.Role"}
      2022-11-23T08:48:43.078-0600    INFO    operator.init   controller/controller.go:241    Starting EventSource    {"controller": "configurable_route_controller", "source": "kind source: *v1.RoleBinding"}
      2022-11-23T08:48:43.078-0600    INFO    operator.init   controller/controller.go:241    Starting Controller     {"controller": "configurable_route_controller"}
      

      Additional info:

      The cited noisiness results from two issues. First, the configurable-route controller needlessly uses source.NewKindWithCache() to configure its watches when it would be sufficient and slightly simpler to use source.Kind.

      Second, recent versions of controller-runtime have excessively noisy logging for the kindWithCache source type. The configurable-route controller was introduced in OpenShift 4.8, which uses controller-runtime v0.9.0-alpha.1. OpenShift 4.9 has controller-runtime v0.9.0, OpenShift 4.10 has controller-runtime v0.11.0, and OpenShift 4.11 has controller-runtime v0.12.0. A change in controller-runtime v0.11.0 causes the noisiness. Before this change, the output was excessively quiet, for example:

      2022-09-28T20:51:40.979Z	INFO	operator.init.controller-runtime.manager.controller.configurable_route_controller	controller/controller.go:221	Starting EventSource	{"source": {}}
      2022-09-28T20:51:40.979Z	INFO	operator.init.controller-runtime.manager.controller.configurable_route_controller	controller/controller.go:221	Starting EventSource	{"source": {}}
      

      I have filed an issue upstream to improve the logging for kindWithCache: https://github.com/kubernetes-sigs/controller-runtime/pull/2057

              mmasters1@redhat.com Miciah Masters
              mmasters1@redhat.com Miciah Masters
              Hongan Li Hongan Li
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Created:
                Updated:
                Resolved: