search

canonical / kubeflow-rocks

Rocks for Kubeflow components
Apache License 2.0
0 stars 11 forks source link

Admission-webhook: Multiple Pebble services when integrated into Charmed Kubeflow #136

Closed mvlassis closed 2 months ago

mvlassis commented 2 months ago

Bug Description

This issue was encountered during the integration of the admission-webhook rock into Charmed Kubeflow, tracked in this issue.

Running the integration tests returns the charm in a blocked state. Looking at the Juju logs, it seems that there are multiple instances of the webhook executable running at the same time. Indeed, after connecting to the admission-webhook container with juju ssh --container admission-webhook admission-webhook/0, and running pebble plan, I get this output:

services:
    admission-webhook:
        summary: Pebble service for admission-webhook-operator
        startup: enabled
        override: replace
        command: /webhook
        on-check-failure:
            admission-webhook-up: restart
    base-admission-webhook:
        startup: enabled
        override: merge
        command: /webhook
        user: ubuntu
checks:
    admission-webhook-up:
        override: replace
        period: 30s
        timeout: 20s
        threshold: 4
        tcp:
            port: 4443
log-targets:
    grafana-agent-k8s/0:
        type: loki
        location: http://grafana-agent-k8s-0.grafana-agent-k8s-endpoints.kubeflow.svc.cluster.local:3500/loki/api/v1/push
        services:
            - all
        override: replace
        labels:
            charm: admission-webhook
            juju_application: admission-webhook
            juju_model: kubeflow
            juju_model_uuid: bd5d2b20-0c02-451e-8ad8-f1dcbf786510
            juju_unit: admission-webhook/0
            product: Juju

We can see that the OCI image has a service named base-admission-webhook, defined here.

Meanwhile, the charm code creates another service named admission-webhook, created here. It seems that there is a conflict between these 2 services that run the same executable, and only 1 service should be created.

To Reproduce

Environment

Python: 3.8 Juju: 3.4.5 Microk8s: 1.29

Relevant Log Output

juju debug-log -i admission-webhook --replay 
unit-admission-webhook-0: 15:49:58 INFO juju.cmd running containerAgent [3.4.5 e5130b8c9e327c81818c849951575b9f3156307d gc go1.21.12]
unit-admission-webhook-0: 15:49:58 INFO juju.cmd.containeragent.unit start "unit"
unit-admission-webhook-0: 15:49:58 INFO juju.worker.upgradesteps upgrade steps for 3.4.5 have already been run.
unit-admission-webhook-0: 15:49:58 INFO juju.worker.probehttpserver starting http server on 127.0.0.1:65301
unit-admission-webhook-0: 15:49:58 INFO juju.api cannot resolve "controller-service.controller-uk8sx.svc.cluster.local": lookup controller-service.controller-uk8sx.svc.cluster.local: operation was canceled
unit-admission-webhook-0: 15:49:58 INFO juju.api connection established to "wss://10.152.183.154:17070/model/6e8f958a-55c4-4cb3-81d6-e46a37fa48fa/api"
unit-admission-webhook-0: 15:49:58 INFO juju.worker.apicaller [6e8f95] "unit-admission-webhook-0" successfully connected to "10.152.183.154:17070"
unit-admission-webhook-0: 15:49:58 INFO juju.worker.migrationminion migration migration phase is now: NONE
unit-admission-webhook-0: 15:49:58 INFO juju.worker.logger logger worker started
unit-admission-webhook-0: 15:49:58 WARNING juju.worker.proxyupdater unable to set snap core settings [proxy.http= proxy.https= proxy.store=]: exec: "snap": executable file not found in $PATH, output: ""
unit-admission-webhook-0: 15:49:58 INFO juju.worker.leadership admission-webhook/0 promoted to leadership of admission-webhook
unit-admission-webhook-0: 15:49:58 INFO juju.worker.caasupgrader abort check blocked until version event received
unit-admission-webhook-0: 15:49:58 INFO juju.worker.caasupgrader unblocking abort check
unit-admission-webhook-0: 15:49:58 INFO juju.agent.tools ensure jujuc symlinks in /var/lib/juju/tools/unit-admission-webhook-0
unit-admission-webhook-0: 15:49:58 INFO juju.worker.uniter unit "admission-webhook/0" started
unit-admission-webhook-0: 15:49:58 INFO juju.worker.uniter resuming charm install
unit-admission-webhook-0: 15:49:58 INFO juju.worker.uniter.charm downloading local:admission-webhook-0 from API server
unit-admission-webhook-0: 15:49:58 INFO juju.downloader downloading from local:admission-webhook-0
unit-admission-webhook-0: 15:49:58 INFO juju.downloader download complete ("local:admission-webhook-0")
unit-admission-webhook-0: 15:49:58 INFO juju.downloader download verified ("local:admission-webhook-0")
unit-admission-webhook-0: 15:50:06 INFO juju.worker.uniter hooks are retried true
unit-admission-webhook-0: 15:50:06 INFO juju.worker.uniter found queued "install" hook
unit-admission-webhook-0: 15:50:07 INFO unit.admission-webhook/0.juju-log Running legacy hooks/install.
unit-admission-webhook-0: 15:50:08 INFO unit.admission-webhook/0.juju-log Generating certificates if missing.
unit-admission-webhook-0: 15:50:08 INFO unit.admission-webhook/0.juju-log Generating certificates..
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install Generating RSA private key, 2048 bit long modulus (2 primes)
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install ....+++++
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install .........................................+++++
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install e is 65537 (0x010001)
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install Generating RSA private key, 2048 bit long modulus (2 primes)
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install ..............................................................................................+++++
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install ...............................................................................................................+++++
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install e is 65537 (0x010001)
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install Signature ok
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install subject=C = GB, ST = Canonical, L = Canonical, O = Canonical, OU = Canonical, CN = 127.0.0.1
unit-admission-webhook-0: 15:50:08 WARNING unit.admission-webhook/0.install Getting CA Private Key
unit-admission-webhook-0: 15:50:08 INFO unit.admission-webhook/0.juju-log Certificates already exist.
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: GET https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log Rendering manifests
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-admin?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-edit?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-view?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterrolebindings/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/admissionregistration.k8s.io/v1/mutatingwebhookconfigurations/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:09 INFO unit.admission-webhook/0.juju-log Reconcile completed successfully
unit-admission-webhook-0: 15:50:10 INFO unit.admission-webhook/0.juju-log HTTP Request: GET https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:10 INFO unit.admission-webhook/0.juju-log Rendering manifests
unit-admission-webhook-0: 15:50:10 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions/poddefaults.kubeflow.org?force=true&fieldManager=lightkube "HTTP/1.1 201 Created"
unit-admission-webhook-0: 15:50:10 INFO unit.admission-webhook/0.juju-log Reconcile completed successfully
unit-admission-webhook-0: 15:50:10 INFO unit.admission-webhook/0.juju-log Pebble plan updated with new configuration, replanning
unit-admission-webhook-0: 15:50:11 ERROR unit.admission-webhook/0.juju-log Traceback (most recent call last):
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/charmed_kubeflow_chisme/pebble/_update_layer.py", line 31, in update_layer
    container.replan()
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/model.py", line 2252, in replan
    self._pebble.replan_services()
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/pebble.py", line 1993, in replan_services
    return self._services_action('replan', [], timeout, delay)
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/pebble.py", line 2090, in _services_action
    raise ChangeError(change.err, change)
ops.pebble.ChangeError: cannot perform the following tasks:
- Start service "base-admission-webhook" (cannot start service: exited quickly with code 0)
----- Logs from task 1 -----
2024-09-13T15:50:11Z INFO Most recent service output:
    {"level":"info","ts":"2024-09-13T15:50:11Z","logger":"controller-runtime.certwatcher","msg":"Updated current TLS certificate"}
    I0913 15:50:11.802163      21 main.go:771] About to start serving webhooks: &http.Server{Addr:":4443", Handler:http.Handler(nil), DisableGeneralOptionsHandler:false, TLSConfig:(*tls.Config)(0xc0001f0d00), ReadTimeout:0, ReadHeaderTimeout:0, WriteTimeout:0, IdleTimeout:0, MaxHeaderBytes:0, TLSNextProto:map[string]func(*http.Server, *tls.Conn, http.Handler)(nil), ConnState:(func(net.Conn, http.ConnState))(nil), ErrorLog:(*log.Logger)(nil), BaseContext:(func(net.Listener) context.Context)(nil), ConnContext:(func(context.Context, net.Conn) context.Context)(nil), inShutdown:atomic.Bool{_:atomic.noCopy{}, v:0x0}, disableKeepAlives:atomic.Bool{_:atomic.noCopy{}, v:0x0}, nextProtoOnce:sync.Once{done:0x0, m:sync.Mutex{state:0, sema:0x0}}, nextProtoErr:error(nil), mu:sync.Mutex{state:0, sema:0x0}, listeners:map[*net.Listener]struct {}(nil), activeConn:map[*http.conn]struct {}(nil), onShutdown:[]func()(nil), listenerGroup:sync.WaitGroup{noCopy:sync.noCopy{}, state:atomic.Uint64{_:atomic.noCopy{}, _:atomic.align64{}, v:0x0}, sema:0x0}}
    {"level":"info","ts":"2024-09-13T15:50:11Z","logger":"controller-runtime.certwatcher","msg":"Starting certificate watcher"}
2024-09-13T15:50:11Z ERROR cannot start service: exited quickly with code 0
-----

unit-admission-webhook-0: 15:50:11 ERROR unit.admission-webhook/0.juju-log Failed to handle <InstallEvent via AdmissionWebhookCharm/on/install[1]> with error: Failed to replan
unit-admission-webhook-0: 15:50:12 INFO unit.admission-webhook/0.juju-log HTTP Request: GET https://10.152.183.1/api/v1/namespaces/kubeflow/services/admission-webhook "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:12 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/api/v1/namespaces/kubeflow/services/admission-webhook "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:12 INFO unit.admission-webhook/0.juju-log Kubernetes service 'admission-webhook' patched successfully
unit-admission-webhook-0: 15:50:12 INFO juju.worker.uniter.operation ran "install" hook (via hook dispatching script: dispatch)
unit-admission-webhook-0: 15:50:13 INFO unit.admission-webhook/0.juju-log logging:1: Generating certificates if missing.
unit-admission-webhook-0: 15:50:13 INFO unit.admission-webhook/0.juju-log logging:1: Certificates already exist.
unit-admission-webhook-0: 15:50:13 INFO juju.worker.uniter.operation ran "logging-relation-created" hook (via hook dispatching script: dispatch)
unit-admission-webhook-0: 15:50:13 INFO juju.worker.uniter found queued "leader-elected" hook
unit-admission-webhook-0: 15:50:14 INFO unit.admission-webhook/0.juju-log Generating certificates if missing.
unit-admission-webhook-0: 15:50:14 INFO unit.admission-webhook/0.juju-log Certificates already exist.
unit-admission-webhook-0: 15:50:14 INFO juju.worker.uniter.operation ran "leader-elected" hook (via hook dispatching script: dispatch)
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log Generating certificates if missing.
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log Certificates already exist.
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log HTTP Request: GET https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log Rendering manifests
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-admin?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-edit?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:15 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterroles/admission-webhook-kubeflow-poddefaults-view?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:16 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/rbac.authorization.k8s.io/v1/clusterrolebindings/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:16 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/admissionregistration.k8s.io/v1/mutatingwebhookconfigurations/admission-webhook?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:16 INFO unit.admission-webhook/0.juju-log Reconcile completed successfully
unit-admission-webhook-0: 15:50:16 INFO unit.admission-webhook/0.juju-log HTTP Request: GET https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:16 INFO unit.admission-webhook/0.juju-log Rendering manifests
unit-admission-webhook-0: 15:50:17 INFO unit.admission-webhook/0.juju-log HTTP Request: PATCH https://10.152.183.1/apis/apiextensions.k8s.io/v1/customresourcedefinitions/poddefaults.kubeflow.org?force=true&fieldManager=lightkube "HTTP/1.1 200 OK"
unit-admission-webhook-0: 15:50:17 INFO unit.admission-webhook/0.juju-log Reconcile completed successfully
unit-admission-webhook-0: 15:50:17 INFO unit.admission-webhook/0.juju-log Pebble plan updated with new configuration, replanning
unit-admission-webhook-0: 15:50:17 ERROR unit.admission-webhook/0.juju-log Traceback (most recent call last):
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/charmed_kubeflow_chisme/pebble/_update_layer.py", line 31, in update_layer
    container.replan()
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/model.py", line 2252, in replan
    self._pebble.replan_services()
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/pebble.py", line 1993, in replan_services
    return self._services_action('replan', [], timeout, delay)
  File "/var/lib/juju/agents/unit-admission-webhook-0/charm/venv/ops/pebble.py", line 2090, in _services_action
    raise ChangeError(change.err, change)
ops.pebble.ChangeError: cannot perform the following tasks:
- Start service "base-admission-webhook" (cannot start service: exited quickly with code 0)
----- Logs from task 0 -----
2024-09-13T15:50:17Z INFO Service "admission-webhook" already started.
----- Logs from task 1 -----
2024-09-13T15:50:17Z INFO Most recent service output:
    {"level":"info","ts":"2024-09-13T15:50:17Z","logger":"controller-runtime.certwatcher","msg":"Updated current TLS certificate"}
    I0913 15:50:17.199753      32 main.go:771] About to start serving webhooks: &http.Server{Addr:":4443", Handler:http.Handler(nil), DisableGeneralOptionsHandler:false, TLSConfig:(*tls.Config)(0xc000502680), ReadTimeout:0, ReadHeaderTimeout:0, WriteTimeout:0, IdleTimeout:0, MaxHeaderBytes:0, TLSNextProto:map[string]func(*http.Server, *tls.Conn, http.Handler)(nil), ConnState:(func(net.Conn, http.ConnState))(nil), ErrorLog:(*log.Logger)(nil), BaseContext:(func(net.Listener) context.Context)(nil), ConnContext:(func(context.Context, net.Conn) context.Context)(nil), inShutdown:atomic.Bool{_:atomic.noCopy{}, v:0x0}, disableKeepAlives:atomic.Bool{_:atomic.noCopy{}, v:0x0}, nextProtoOnce:sync.Once{done:0x0, m:sync.Mutex{state:0, sema:0x0}}, nextProtoErr:error(nil), mu:sync.Mutex{state:0, sema:0x0}, listeners:map[*net.Listener]struct {}(nil), activeConn:map[*http.conn]struct {}(nil), onShutdown:[]func()(nil), listenerGroup:sync.WaitGroup{noCopy:sync.noCopy{}, state:atomic.Uint64{_:atomic.noCopy{}, _:atomic.align64{}, v:0x0}, sema:0x0}}
    {"level":"info","ts":"2024-09-13T15:50:17Z","logger":"controller-runtime.certwatcher","msg":"Starting certificate watcher"}
2024-09-13T15:50:17Z ERROR cannot start service: exited quickly with code 0
-----

Additional Context

This issue could be fixed by ensuring that only 1 service is created, by having the same name value in both places.

syncronize-issues-to-jira[bot] commented 2 months ago

Thank you for reporting us your feedback!

The internal ticket has been created: https://warthogs.atlassian.net/browse/KF-6263.

This message was autogenerated