+++ This bug was initially created as a clone of Bug #1808102 +++ Description of problem: Dependency mismatch in Ansible Operator base image prevents reconciliation from occurring, because ansible-runner-http cannot communicate events over the socket. Version-Release number of selected component (if applicable): 4.4 How reproducible: 100% Steps to Reproduce: 1. Install and run any ansible-based operator (for example, the template-service-broker-operator) 2. Create the proper Custom Resource to kick off reconciliation Actual results: $ oc logs -f openshift-template-service-broker-operator-d4bd6b6c7-qk5wv {"level":"info","ts":1582190464.3036518,"logger":"cmd","msg":"Go Version: go1.13.4"} {"level":"info","ts":1582190464.3037083,"logger":"cmd","msg":"Go OS/Arch: linux/amd64"} {"level":"info","ts":1582190464.3037162,"logger":"cmd","msg":"Version of operator-sdk: v0.12.0+git"} {"level":"info","ts":1582190464.3037367,"logger":"cmd","msg":"Watching namespace.","Namespace":"openshift-template-service-broker"} {"level":"info","ts":1582190466.6216123,"logger":"controller-runtime.metrics","msg":"metrics server is starting to listen","addr":"0.0.0.0:8383"} {"level":"info","ts":1582190466.6221745,"logger":"watches","msg":"Failed to parse %v from environment. Using default %v","WORKER_TEMPLATESERVICEBROKER_OSB_OPENSHIFT_IO":1} {"level":"info","ts":1582190466.6221993,"logger":"watches","msg":"Failed to parse %v from environment. Using default %v","ANSIBLE_VERBOSITY_TEMPLATESERVICEBROKER_OSB_OPENSHIFT_IO":2} {"level":"info","ts":1582190466.6222587,"logger":"ansible-controller","msg":"Watching resource","Options.Group":"osb.openshift.io","Options.Version":"v1","Options.Kind":"TemplateServiceBroker"} {"level":"info","ts":1582190466.6225896,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582190466.6228318,"logger":"leader","msg":"Trying to become the leader."} {"level":"info","ts":1582190468.9473782,"logger":"leader","msg":"No pre-existing lock was found."} {"level":"info","ts":1582190468.9583323,"logger":"leader","msg":"Became the leader."} {"level":"info","ts":1582190473.652566,"logger":"metrics","msg":"Metrics Service object created","Service.Name":"openshift-template-service-broker-operator-metrics","Service.Namespace":"openshift-template-service-broker"} {"level":"info","ts":1582190473.6562455,"logger":"proxy","msg":"Starting to serve","Address":"127.0.0.1:8888"} {"level":"info","ts":1582190473.6565778,"logger":"controller-runtime.manager","msg":"starting metrics server","path":"/metrics"} {"level":"info","ts":1582190473.757262,"logger":"controller-runtime.controller","msg":"Starting Controller","controller":"templateservicebroker-controller"} {"level":"info","ts":1582190473.8574772,"logger":"controller-runtime.controller","msg":"Starting workers","controller":"templateservicebroker-controller","worker count":1} {"level":"error","ts":1582190782.8844702,"logger":"runner","msg":"Traceback (most recent call last):\n File \"/usr/lib/python2.7/site-packages/ansible_runner/__main__.py\", line 329, in main\n res = run(**run_options)\n File \"/usr/lib/python2.7/site-packages/ansible_runner/interface.py\", line 162, in run\n r.run()\n File \"/usr/lib/python2.7/site-packages/ansible_runner/runner.py\", line 93, in run\n self.status_callback('starting')\n File \"/usr/lib/python2.7/site-packages/ansible_runner/runner.py\", line 84, in status_callback\n ansible_runner.plugins[plugin].status_handler(self.config, status_data)\n File \"/usr/lib/python2.7/site-packages/ansible_runner_http/events.py\", line 38, in status_handler\n urlpath=plugin_config['runner_path'])\n File \"/usr/lib/python2.7/site-packages/ansible_runner_http/events.py\", line 18, in send_request\n return session.post(url_actual, headers=headers, json=(data))\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 529, in post\n return self.request('POST', url, data=data, json=json, **kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 486, in request\n resp = self.send(prep, **send_kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 598, in send\n r = adapter.send(request, **kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/adapters.py\", line 370, in send\n timeout=timeout\n File \"/usr/lib/python2.7/site-packages/urllib3/connectionpool.py\", line 587, in urlopen\n timeout_obj = self._get_timeout(timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/connectionpool.py\", line 302, in _get_timeout\n return Timeout.from_float(timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 154, in from_float\n return Timeout(read=timeout, connect=timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 94, in __init__\n self._connect = self._validate_timeout(connect, 'connect')\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 127, in _validate_timeout\n \"int, float or None.\" % (name, value))\nValueError: Timeout value connect was Timeout(connect=None, read=None, total=None), but it must be an int, float or None.\n","job":"6129484611666145821","name":"template-service-broker","namespace":"openshift-template-service-broker","error":"exit status 1","stacktrace":"github.com/go-logr/zapr.(*zapLogger).Error\n\tsrc/github.com/operator-framework/operator-sdk/vendor/github.com/go-logr/zapr/zapr.go:128\ngithub.com/operator-framework/operator-sdk/pkg/ansible/runner.(*runner).Run.func1\n\tsrc/github.com/operator-framework/operator-sdk/pkg/ansible/runner/runner.go:199"} {"level":"error","ts":1582190782.8848586,"logger":"reconciler","msg":"Failed to get ansible-runner stdout","job":"6129484611666145821","name":"template-service-broker","namespace":"openshift-template-service-broker","error":"open /tmp/ansible-operator/runner/osb.openshift.io/v1/TemplateServiceBroker/openshift-template-service-broker/template-service-broker/artifacts/6129484611666145821/stdout: no such file or directory","stacktrace":"github.com/go-logr/zapr.(*zapLogger).Error\n\tsrc/github.com/operator-framework/operator-sdk/vendor/github.com/go-logr/zapr/zapr.go:128\ngithub.com/operator-framework/operator-sdk/pkg/ansible/controller.(*AnsibleOperatorReconciler).Reconcile\n\tsrc/github.com/operator-framework/operator-sdk/pkg/ansible/controller/reconcile.go:183\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:216\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:192\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:171\nk8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152\nk8s.io/apimachinery/pkg/util/wait.JitterUntil\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:153\nk8s.io/apimachinery/pkg/util/wait.Until\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88"} {"level":"error","ts":1582190782.8850884,"logger":"controller-runtime.controller","msg":"Reconciler error","controller":"templateservicebroker-controller","request":"openshift-template-service-broker/template-service-broker","error":"open /tmp/ansible-operator/runner/osb.openshift.io/v1/TemplateServiceBroker/openshift-template-service-broker/template-service-broker/artifacts/6129484611666145821/stdout: no such file or directory","stacktrace":"github.com/go-logr/zapr.(*zapLogger).Error\n\tsrc/github.com/operator-framework/operator-sdk/vendor/github.com/go-logr/zapr/zapr.go:128\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:218\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:192\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:171\nk8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152\nk8s.io/apimachinery/pkg/util/wait.JitterUntil\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:153\nk8s.io/apimachinery/pkg/util/wait.Until\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:88"} {"level":"error","ts":1582190784.2685933,"logger":"runner","msg":"Traceback (most recent call last):\n File \"/usr/lib/python2.7/site-packages/ansible_runner/__main__.py\", line 329, in main\n res = run(**run_options)\n File \"/usr/lib/python2.7/site-packages/ansible_runner/interface.py\", line 162, in run\n r.run()\n File \"/usr/lib/python2.7/site-packages/ansible_runner/runner.py\", line 93, in run\n self.status_callback('starting')\n File \"/usr/lib/python2.7/site-packages/ansible_runner/runner.py\", line 84, in status_callback\n ansible_runner.plugins[plugin].status_handler(self.config, status_data)\n File \"/usr/lib/python2.7/site-packages/ansible_runner_http/events.py\", line 38, in status_handler\n urlpath=plugin_config['runner_path'])\n File \"/usr/lib/python2.7/site-packages/ansible_runner_http/events.py\", line 18, in send_request\n return session.post(url_actual, headers=headers, json=(data))\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 529, in post\n return self.request('POST', url, data=data, json=json, **kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 486, in request\n resp = self.send(prep, **send_kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/sessions.py\", line 598, in send\n r = adapter.send(request, **kwargs)\n File \"/usr/lib/python2.7/site-packages/requests/adapters.py\", line 370, in send\n timeout=timeout\n File \"/usr/lib/python2.7/site-packages/urllib3/connectionpool.py\", line 587, in urlopen\n timeout_obj = self._get_timeout(timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/connectionpool.py\", line 302, in _get_timeout\n return Timeout.from_float(timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 154, in from_float\n return Timeout(read=timeout, connect=timeout)\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 94, in __init__\n self._connect = self._validate_timeout(connect, 'connect')\n File \"/usr/lib/python2.7/site-packages/urllib3/util/timeout.py\", line 127, in _validate_timeout\n \"int, float or None.\" % (name, value))\nValueError: Timeout value connect was Timeout(connect=None, read=None, total=None), but it must be an int, float or None.\n","job":"4037200794235010051","name":"template-service-broker","namespace":"openshift-template-service-broker","error":"exit status 1","stacktrace":"github.com/go-logr/zapr.(*zapLogger).Error\n\tsrc/github.com/operator-framework/operator-sdk/vendor/github.com/go-logr/zapr/zapr.go:128\ngithub.com/operator-framework/operator-sdk/pkg/ansible/runner.(*runner).Run.func1\n\tsrc/github.com/operator-framework/operator-sdk/pkg/ansible/runner/runner.go:199"} {"level":"error","ts":1582190784.2689536,"logger":"reconciler","msg":"Failed to get ansible-runner stdout","job":"4037200794235010051","name":"template-service-broker","namespace":"openshift-template-service-broker","error":"open /tmp/ansible-operator/runner/osb.openshift.io/v1/TemplateServiceBroker/openshift-template-service-broker/template-service-broker/artifacts/4037200794235010051/stdout: no such file or directory","stacktrace":"github.com/go-logr/zapr.(*zapLogger).Error\n\tsrc/github.com/operator-framework/operator-sdk/vendor/github.com/go-logr/zapr/zapr.go:128\ngithub.com/operator-framework/operator-sdk/pkg/ansible/controller.(*AnsibleOperatorReconciler).Reconcile\n\tsrc/github.com/operator-framework/operator-sdk/pkg/ansible/controller/reconcile.go:183\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:216\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:192\nsigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).worker\n\tsrc/github.com/operator-framework/operator-sdk/vendor/sigs.k8s.io/controller-runtime/pkg/internal/controller/controller.go:171\nk8s.io/apimachinery/pkg/util/wait.JitterUntil.func1\n\tsrc/github.com/operator-framework/operator-sdk/vendor/k8s.io/apimachinery/pkg/util/wait/wait.go:152\nk8s.io/apimachinery/pkg/util/wait.JitterUntil\n\tsrc/github.com/operator-framework/operator- Expected results: Operator successfully runs Additional info:
Verified. Cluster version: 4.4.0-0.nightly-2020-02-25-122356 $ oc get csv -n openshift-template-service-broker NAME DISPLAY VERSION REPLACES PHASE openshifttemplateservicebrokeroperator.4.4.0-202002270901 OpenShift Template Service Broker Operator 4.4.0-202002270901 Succeeded $ oc get po -n openshift-template-service-broker NAME READY STATUS RESTARTS AGE apiserver-2-deploy 0/1 Completed 0 3m6s apiserver-2-gtlbs 1/1 Running 0 3m1s openshift-template-service-broker-operator-75b5b486d-xjdsh 1/1 Running 0 17m $ oc logs -f openshift-template-service-broker-operator-75b5b486d-xjdsh {"level":"info","ts":1582877502.575054,"logger":"cmd","msg":"Go Version: go1.13.4"} {"level":"info","ts":1582877502.575086,"logger":"cmd","msg":"Go OS/Arch: linux/amd64"} {"level":"info","ts":1582877502.57509,"logger":"cmd","msg":"Version of operator-sdk: v0.12.0+git"} {"level":"info","ts":1582877502.5751038,"logger":"cmd","msg":"Watching namespace.","Namespace":"openshift-template-service-broker"} {"level":"info","ts":1582877504.881091,"logger":"controller-runtime.metrics","msg":"metrics server is starting to listen","addr":"0.0.0.0:8383"} {"level":"info","ts":1582877504.882064,"logger":"watches","msg":"Failed to parse %v from environment. Using default %v","WORKER_TEMPLATESERVICEBROKER_OSB_OPENSHIFT_IO":1} {"level":"info","ts":1582877504.8820877,"logger":"watches","msg":"Failed to parse %v from environment. Using default %v","ANSIBLE_VERBOSITY_TEMPLATESERVICEBROKER_OSB_OPENSHIFT_IO":2} {"level":"info","ts":1582877504.882132,"logger":"ansible-controller","msg":"Watching resource","Options.Group":"osb.openshift.io","Options.Version":"v1","Options.Kind":"TemplateServiceBroker"} {"level":"info","ts":1582877504.8823855,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582877504.8825443,"logger":"leader","msg":"Trying to become the leader."} {"level":"info","ts":1582877507.1978598,"logger":"leader","msg":"No pre-existing lock was found."} {"level":"info","ts":1582877507.2054505,"logger":"leader","msg":"Became the leader."} {"level":"info","ts":1582877511.9299388,"logger":"metrics","msg":"Metrics Service object created","Service.Name":"openshift-template-service-broker-operator-metrics","Service.Namespace":"openshift-template-service-broker"} {"level":"info","ts":1582877511.931552,"logger":"proxy","msg":"Starting to serve","Address":"127.0.0.1:8888"} {"level":"info","ts":1582877511.931719,"logger":"controller-runtime.manager","msg":"starting metrics server","path":"/metrics"} {"level":"info","ts":1582877512.031874,"logger":"controller-runtime.controller","msg":"Starting Controller","controller":"templateservicebroker-controller"} {"level":"info","ts":1582877512.1320791,"logger":"controller-runtime.controller","msg":"Starting workers","controller":"templateservicebroker-controller","worker count":1} {"level":"info","ts":1582877625.7347991,"logger":"logging_event_handler","msg":"[playbook task]","name":"template-service-broker","namespace":"openshift-template-service-broker","gvk":"osb.openshift.io/v1, Kind=TemplateServiceBroker","event_type":"playbook_on_task_start","job":"4037200794235010051","EventData.Name":"Validation"} {"level":"info","ts":1582877625.7831213,"logger":"logging_event_handler","msg":"[playbook task]","name":"template-service-broker","namespace":"openshift-template-service-broker","gvk":"osb.openshift.io/v1, Kind=TemplateServiceBroker","event_type":"playbook_on_task_start","job":"4037200794235010051","EventData.Name":"Run template-service-broker role"} {"level":"info","ts":1582877626.195513,"logger":"logging_event_handler","msg":"[playbook task]","name":"template-service-broker","namespace":"openshift-template-service-broker","gvk":"osb.openshift.io/v1, Kind=TemplateServiceBroker","event_type":"playbook_on_task_start","job":"4037200794235010051","EventData.Name":"template-service-broker : Set tsb objects state=present"} {"level":"info","ts":1582877629.42366,"logger":"proxy","msg":"Cache miss: /v1, Kind=ServiceAccount, openshift-template-service-broker/apiserver"} {"level":"info","ts":1582877629.4294393,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877629.4297712,"logger":"proxy","msg":"Watching child resource","kind":"/v1, Kind=ServiceAccount","enqueue_kind":"osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582877629.4298913,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: /v1, Kind=ServiceAccount"} {"level":"info","ts":1582877630.090335,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877630.7633152,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877632.5115201,"logger":"proxy","msg":"Cache miss: apps.openshift.io/v1, Kind=DeploymentConfig, openshift-template-service-broker/apiserver"} {"level":"info","ts":1582877632.5241218,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877632.524483,"logger":"proxy","msg":"Watching child resource","kind":"apps.openshift.io/v1, Kind=DeploymentConfig","enqueue_kind":"osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582877632.5245101,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: apps.openshift.io/v1, Kind=DeploymentConfig"} {"level":"info","ts":1582877633.2936316,"logger":"proxy","msg":"Cache miss: /v1, Kind=ConfigMap, openshift-template-service-broker/apiserver-config"} {"level":"info","ts":1582877633.2997205,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877633.300024,"logger":"proxy","msg":"Watching child resource","kind":"/v1, Kind=ConfigMap","enqueue_kind":"osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582877633.3000572,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: /v1, Kind=ConfigMap"} {"level":"info","ts":1582877634.0597928,"logger":"proxy","msg":"Cache miss: /v1, Kind=Service, openshift-template-service-broker/apiserver"} {"level":"info","ts":1582877634.0740337,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877634.0743365,"logger":"proxy","msg":"Watching child resource","kind":"/v1, Kind=Service","enqueue_kind":"osb.openshift.io/v1, Kind=TemplateServiceBroker"} {"level":"info","ts":1582877634.0743587,"logger":"controller-runtime.controller","msg":"Starting EventSource","controller":"templateservicebroker-controller","source":"kind source: /v1, Kind=Service"} {"level":"info","ts":1582877634.8406346,"logger":"proxy","msg":"Cache miss: /v1, Kind=ConfigMap, openshift-template-service-broker/apiserver-service-ca-bundle"} {"level":"info","ts":1582877634.8473241,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877635.5219548,"logger":"proxy","msg":"Cache miss: /v1, Kind=ServiceAccount, openshift-template-service-broker/template-service-broker-client"} {"level":"info","ts":1582877635.5883653,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877636.3230052,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877637.0859134,"logger":"proxy","msg":"Injecting owner reference"} {"level":"info","ts":1582877637.8535345,"logger":"proxy","msg":"Cache miss: /v1, Kind=Secret, openshift-template-service-broker/template-service-broker-client"} {"level":"info","ts":1582877637.8588345,"logger":"proxy","msg":"Injecting owner reference"} $ oc logs -f apiserver-2-gtlbs I0228 08:26:18.009520 1 secure_serving.go:116] Serving securely on [::]:8443 I0228 08:26:18.010964 1 controller_utils.go:1027] Waiting for caches to sync for tsb controller I0228 08:26:18.711236 1 controller_utils.go:1034] Caches are synced for tsb controller
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-2020:0581