kopf can't post events

[kopf-archiver]

An issue by olivier-mauras at 2019-08-05 15:27:11+00:00
Original URL: zalando-incubator/kopf#164
 

Expected Behavior

Be able to post events either custom of defaults.

Actual Behavior

Custom event with kopf.info()
[2019-08-05 15:09:56,422] kopf.clients.events  [WARNING ] Failed to post an event. Ignoring and continuing. Error: HTTPError('Event "kopf-event-tvlgd" is invalid: involvedObject.namespace: Invalid value: "": does not match event.namespace'). Event: type='Normal', reason='SA_DELETED', message='Managed service account got deleted'.

Default events:
[2019-08-05 15:12:47,217] kopf.clients.events  [WARNING ] Failed to post an event. Ignoring and continuing. Error: HTTPError('Event "kopf-event-5zplb" is invalid: involvedObject.namespace: Invalid value: "": does not match event.namespace'). Event: type='Normal', reason='Logging', message="Handler 'create_ns' succeeded.".

Steps to Reproduce the Problem

No particular code is actually running
My controller is running with a cluster-admin role in it's own namespace.

---
apiVersion: v1
kind: ServiceAccount
metadata:
  namespace: kopf-controllers
  name: namespace-manager
---
apiVersion: rbac.authorization.k8s.io/v1beta1
kind: ClusterRoleBinding
metadata:
  name: namespace-manager-rolebinding-cluster
roleRef:
  apiGroup: rbac.authorization.k8s.io
  kind: ClusterRole
  name: cluster-admin
subjects:
  - kind: ServiceAccount
    name: namespace-manager
    namespace: kopf-controllers

A simple example like this gives the same result:

import kopf

@kopf.on.resume('', 'v1', 'namespaces')
@kopf.on.create('', 'v1', 'namespaces')
def create_fn(spec, **kwargs):
    print(f"And here we are! Creating: {spec}")
    return {'message': 'hello world'}  # will be the new status

Run with: kopf run --standalone ./example.py

...
[2019-08-05 15:19:54,389] kopf.clients.events  [WARNING ] Failed to post an event. Ignoring and continuing. Error: HTTPError('Event "kopf-event-27kj9" is invalid: involvedObject.namespace: Invalid value: "": does not match event.namespace'). Event: type='Normal', reason='Logging', message='All handlers succeeded for resuming.'.
[2019-08-05 15:19:54,402] kopf.clients.events  [WARNING ] Failed to post an event. Ignoring and continuing. Error: HTTPError('Event "kopf-event-vdnqq" is invalid: involvedObject.namespace: Invalid value: "": does not match event.namespace'). Event: type='Normal', reason='Logging', message="Handler 'create_fn' succeeded.".
[2019-08-05 15:19:54,416] kopf.clients.events  [WARNING ] Failed to post an event. Ignoring and continuing. Error: HTTPError('Event "kopf-event-xf2ht" is invalid: involvedObject.namespace: Invalid value: "": does not match event.namespace'). Event: type='Normal', reason='Logging', message='All handlers succeeded for update.'.
...

Specifications

• Platform: Linux
• Kubernetes version:

Client Version: version.Info{Major:"1", Minor:"12", GitVersion:"v1.12.7", GitCommit:"6f482974b76db3f1e0f5d24605a9d1d38fad9a2b", GitTreeState:"clean", BuildDate:"2019-03-25T02:52:13Z", GoVersion:"go1.10.8", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"11", GitVersion:"v1.11.6", GitCommit:"b1d75deca493a24a2f87eb1efde1a569e52fc8d9", GitTreeState:"clean", BuildDate:"2018-12-16T04:30:10Z", GoVersion:"go1.10.3", Compiler:"gc", Platform:"linux/amd64"}

• Python version: Python 3.7.4
• Python packages installed:

# pip freeze --all
aiohttp==3.5.4
aiojobs==0.2.2
async-timeout==3.0.1
attrs==19.1.0
cachetools==3.1.1
certifi==2019.6.16
chardet==3.0.4
Click==7.0
google-auth==1.6.3
idna==2.8
iso8601==0.1.12
kopf==0.20
kubernetes==10.0.0
multidict==4.5.2
oauthlib==3.0.2
pip==19.1.1
pyasn1==0.4.5
pyasn1-modules==0.2.5
pykube-ng==0.28
python-dateutil==2.8.0
PyYAML==5.1.2
requests==2.22.0
requests-oauthlib==1.2.0
rsa==4.0
setuptools==41.0.1
six==1.12.0
urllib3==1.25.3
websocket-client==0.56.0
wheel==0.33.4
yarl==1.3.0

---

Commented by nolar at 2019-08-05 17:25:59+00:00
 

olivier-mauras Thanks for reporting.

I fought with this issue few times, to no avail.

Brief summary: K8s events are namespaced, there are no cluster-scoped events. Also, k8s events can refer to an object via spec.involvedObject of type ObjectReference. This structure contains namespace field, to refer to the involved object's namespace (also, name, uid, etc).

I could not find a way to post namespaced events for cluster-scoped resources. It always fails with namespace mismatch (regardless of which library is used).

For an isolated example, here is an attempt to do this for kind: Node. The same happens for any cluster-scoped involvedObject though.

minikube start
curl -i \
  --cacert ~/.minikube/ca.crt --cert ~/.minikube/client.crt --key ~/.minikube/client.key    \
  -X POST -H "Content-Type: application/json" \
  https://192.168.64.15:8443/api/v1/namespaces/default/events    \
   -d '{
   "metadata": {"namespace": "default", "generateName": "kopf-event-"},
   "action": "Action?", "type": "SomeType", "reason": "SomeReason", "message": "Some message", "reportingComponent": "kopf", "reportingInstance": "dev", "source": {"component": "kopf"},
   "firstTimestamp": "2019-08-05T16:44:56.078476Z", "lastTimestamp": "2019-08-05T16:44:56.078476Z", "eventTime": "2019-08-05T16:44:56.078476Z",
   "involvedObject": {"kind": "Node", "name": "minikube", "uid": "minikube"}}'

HTTP/2 422 
content-type: application/json
content-length: 532
date: Mon, 05 Aug 2019 17:19:09 GMT

{
  "kind": "Status",
  "apiVersion": "v1",
  "metadata": {
    
  },
  "status": "Failure",
  "message": "Event \"kopf-event-8h65p\" is invalid: involvedObject.namespace: Invalid value: \"\": does not match event.namespace",
  "reason": "Invalid",
  "details": {
    "name": "kopf-event-8h65p",
    "kind": "Event",
    "causes": [
      {
        "reason": "FieldValueInvalid",
        "message": "Invalid value: \"\": does not match event.namespace",
        "field": "involvedObject.namespace"
      }
    ]
  },
  "code": 422
}

If I assign a namespace to the involved object, in the assumption that the cluster-scoped object kind of "exists" in all namespaces at once, then the event is created. However, it is not shown on kubectl describe, as the attachment is wrong.

---

Surprisingly, in the same minikube deployment, I can see such events for kind: Node via:

kubectl get events -o yaml | less

- apiVersion: v1
  count: 1
  eventTime: null
  firstTimestamp: "2019-08-05T16:38:01Z"
  involvedObject:
    kind: Node
    name: minikube
    uid: minikube
  kind: Event
  lastTimestamp: "2019-08-05T16:38:01Z"
  message: Starting kubelet.
  metadata:
    creationTimestamp: "2019-08-05T16:38:11Z"
    name: minikube.15b8143362eeb00f
    namespace: default
    resourceVersion: "193"
    selfLink: /api/v1/namespaces/default/events/minikube.15b8143362eeb00f
    uid: d23980be-d745-40c7-8378-656fe2b31cb7
  reason: Starting
  reportingComponent: ""
  reportingInstance: ""
  source:
    component: kubelet
    host: minikube
  type: Normal

So, conceptually it is possible for a namespaced event to refer to a non-namespaced object. But the API does not allow to do this, or I do it somehow wrong. The API documentation gives no clues on how to post such events.

---

Any help on how such events can or should be posted, is welcomed.

What I can do here, is to fix a little bit, to post the events to the current context's namespace (i.e. with the broken link, as explained above). At least, they will be visible there via kubectl get events. Though, it is unclear what is the use-case of the events except for kubectl describe. But the error messages in Kopf will be gone.

---

Commented by olivier-mauras at 2019-08-06 06:16:03+00:00
 

nolar Thanks for your extended reply.
Maybe I should describe my usecase to make things a bit more clear and maybe find an acceptable workaround. I actually don't mind at all the noise of the default events and had already ran kopf in quiet mode :)

Right now my controller is handling namespaces creations/update. For each namespace handled, the controller will create a set of predefined namespaced resources - service acounts, network policies.

I've seen your other comments about handling children deletions and indeed I thought it would be smart and as non convoluted as possible to have an on.delete handler for the children resources that would actually send a "delete" event to the namespace.

So here's my code

@kopf.on.delete('', 'v1', 'serviceaccounts', annotations={'custom/created_by': 'namespace-manager'})
async def sa_delete(body, namespace,  **kwargs):
  try:
    api = kubernetes.client.CoreV1Api()
    ns = api.read_namespace(name=namespace)
  except ApiException as err:
    sprint('ERROR', 'Exception when calling CoreV1Api->read_namespace: {}'.format(err))

  kopf.info(ns.to_dict(), reason='SA_DELETED', message='Managed service account got deleted')
  return

And so here's the problem with the event not working is that I can't "notify" the namespace of the modification.
What would be the best solution for this problem if we can't send event at this point?

---

Commented by olivier-mauras at 2019-08-06 07:07:50+00:00
 

Answering myself, something along the following that you posted in #153 would certainly work well

@kopf.on.event('', 'v1', 'services')
def service_event(meta, name, namespace, event, **_):
    # filter out irrelevant services
    if not meta.get('labels', {}).get('my-app'):
        return

    # Now, it is surely our service.
    # NB: the old service is already absent at this event, so there will be no HTTP 409 conflict.
    if event['type'] == 'DELETED':
        _recreate_service(name, namespace)

---

Commented by nolar at 2019-08-06 08:49:02+00:00
 

olivier-mauras Ah, I see your point.

Just to clarify: Kopf is not a K8s client library, and is not going to be such. It only tries to be friendly to all existing K8s client libraries, leaving this choice to the developers.

The k8s-events support in Kopf is rudimentary: only to the extent needed for K8s<->Python integration of per-object logging (i.e. Python's logging system posting to /api/v1/.../events transparently). Plus some methods are publicly exposed also for the current object's logging.

This is the main purpose of Kopf: to marshal K8s activities/structures into Python primitives/functions/libraries, and back from Python to K8s.

Non-current object's logging is not intended as a feature (though, may work as a side effect, as in your example).

If you need to post some other sophisticated events for some other objects, you can use a client library API calls directly. In case of kubernetes client, it is CoreV1Api.create_namespaced_event. Some hints on the body's content can be taken from Kopf (kopf.clients.events).

---

Commented by nolar at 2019-08-06 08:50:34+00:00
 

olivier-mauras Regarding the code example, please note, that label-filtering is now possible via the decorator kwargs, so that it will suppress excessive logging for not-matching objects: https://kopf.readthedocs.io/en/latest/handlers/#filtering

---

Commented by olivier-mauras at 2019-08-06 08:53:42+00:00
 

nolar Thanks for your clarification, as you say what I thought as a feature is more a side effect :)
I just implemented the on.event() sample and it's works well enough in my use case

---

Commented by nolar at 2019-09-26 14:30:41+00:00
 

The changes are now in kopf==0.21. If the issue reappears, feel free to re-open.

---

Commented by cliffburdick at 2020-05-28 02:17:23+00:00
 

nolar for what it's worth, I'm seeing this in 0.27rc6. Periodically I see the following messages in the logs:

Failed to post an event. Ignoring and continuing. Status: 500. Message: Internal Server Error. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".
Failed to post an event. Ignoring and continuing. Status: 500. Message: Internal Server Error. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".

I have a timer called MonitorTriadSets that's set to interval=3, idle=3.

---

Commented by cliffburdick at 2020-08-01 04:17:01+00:00
 

nolar for what it's worth, I'm seeing this in 0.27rc6. Periodically I see the following messages in the logs:

Failed to post an event. Ignoring and continuing. Status: 500. Message: Internal Server Error. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".
Failed to post an event. Ignoring and continuing. Status: 500. Message: Internal Server Error. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".

I have a timer called MonitorTriadSets that's set to interval=3, idle=3.

nolar do you think this can be reopened since it appears to be occurring on timers? I'm not sure if there's a newer version maybe, but it seems the project hasn't been updated in many months.

[cliffburdick]

Hi @nolar it seems this is still happening with 0.28:

Failed to post an event. Ignoring and continuing. Status: 500. Message: The POST operation against Event could not be completed at this time, please try again.. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".
Failed to post an event. Ignoring and continuing. Status: 500. Message: The POST operation against Event could not be completed at this time, please try again.. Event: type='Normal', reason='Logging', message="Timer 'MonitorTriadSets' succeeded.".

[JohnRusk]

Looks like the error message, mentioned by @cliffburdick , was changed to something that explains the problem better, in K8s 1.23 in this PR kubernetes/kubernetes#104699