kopf icon indicating copy to clipboard operation
kopf copied to clipboard
verified publisher icon nolar

on.create() handler keeps getting fired every time object is modified

Open michal0000000 opened this issue 2 years ago • 2 comments

Long story short

I've implemented a firewall operator that assigns externalIPs to LoadBalancer services. The problem it that the on.create() handler keeps getting fired not only upon service creation, but also upon every modification of the service.

Ive tested this by creating a simple Watch stream in python to see if the problem is in Kubernetes uncorrectly handling serivce modification of if kopf treats modifications as creation.

python watcher

import kopf
import kubernetes
import yaml
import pprint
kubernetes.config.load_kube_config()
api = kubernetes.client.CoreV1Api()
w = kubernetes.watch.Watch()
# Start watching for service creation across all namespaces
for event in w.stream(api.list_service_for_all_namespaces):
    svc = event['object']
    print(f"Service {svc.metadata.name} {event['type']} in namespace {svc.metadata.namespace}")

watcher stdout

Service siem-kafka-zookeeper-client MODIFIED in namespace siem-strimzi
Service siem-kafka-zookeeper-nodes MODIFIED in namespace siem-strimzi
Service siem-kafka-zookeeper-client MODIFIED in namespace siem-strimzi
Service siem-kafka-zookeeper-nodes MODIFIED in namespace siem-strimzi
Service siem-kafka-zookeeper-client MODIFIED in namespace siem-strimzi
Service siem-kafka-zookeeper-nodes MODIFIED in namespace siem-strimzi
Service siem-kafka-kafka-brokers MODIFIED in namespace siem-strimzi

The intervarls of modification from my script match the logs I see in the kopf operator.

Expected behaviour

Kopf should only invoke the on.create() decorator if an object is created - event['type'] returned from Watch.stream() retyrbs ADDED instead of MODIFIED

Am I misunderstanding how kopf works?

Kopf version

1.36.2

Kubernetes version

1.26.1

Python version

python3.9.17

Code

@kopf.on.startup()
def configure(settings: kopf.OperatorSettings, **_):
    settings.execution.max_workers = 5

@kopf.on.create('v1', 'services', retries=5, backoff=10)
def create_svc(body, spec, **kwargs):

    # Get info from object
    svc_name = body['metadata']['name']
    svc_namespace = body['metadata']['namespace']
    obj_type = spec['type']

    # If not LB, do nothing
    if obj_type == None or obj_type.lower() != 'loadbalancer':
        return

    # Verfiy object has not been previously processed
    annotations = body['metadata'].get('annotations', None)
    if annotations != None:
        server_pool = annotations.get('operator.io/server_pool_link', None)
        if server_pool != None:
            return

    # ...
    # Do its thing
    # ...

    # Assign externalIP, annotations
    service_patch = {
            'metadata': {
                'annotations' : {
                    'operator.io/server_pool_link': pool_link,
                    'operator.io/fw_policy_link': new_policy_link}
                },
            'spec':{
                'externalIPs':[available_pool[0]]
                }
            }

    # Validate changes
    try:
        # Patch LoadBalancer object
        api_response = api.patch_namespaced_service(
            name=svc_name,
            namespace=svc_namespace,
            body=service_patch,
            field_validation='Strict')

    except Exception as e:
        logging.info(f'HANDLER on.create: Object patch failed, received error: {e}')
        
@kopf.on.delete('v1', 'services', retries=5, backoff=10)
def delete_svc(body, spec, **kwargs):
    # undos changes on fw

Logs

[2023-10-19 14:41:05,054] asyncio              [DEBUG   ] Using selector: EpollSelector
[2023-10-19 14:41:05,058] kopf._core.reactor.r [DEBUG   ] Starting Kopf 1.36.2.
[2023-10-19 14:41:05,059] kopf.activities.star [DEBUG   ] Activity 'configure' is invoked.
[2023-10-19 14:41:05,061] kopf.activities.star [INFO    ] Activity 'configure' succeeded.
[2023-10-19 14:41:05,063] kopf._core.engines.a [INFO    ] Initial authentication has been initiated.
[2023-10-19 14:41:05,063] kopf.activities.auth [DEBUG   ] Activity 'login_via_client' is invoked.
[2023-10-19 14:41:05,067] kopf._core.engines.p [DEBUG   ] Serving health status at http://0.0.0.0:8080/healthz
[2023-10-19 14:41:05,068] kopf.activities.auth [DEBUG   ] Client is configured in cluster with service account.
[2023-10-19 14:41:05,070] kopf.activities.auth [INFO    ] Activity 'login_via_client' succeeded.
[2023-10-19 14:41:05,071] kopf._core.engines.a [INFO    ] Initial authentication has finished.
[2023-10-19 14:41:05,128] kopf._cogs.clients.w [DEBUG   ] Starting the watch-stream for customresourcedefinitions.v1.apiextensions.k8s.io cluster-wide.
[2023-10-19 14:41:05,130] kopf._cogs.clients.w [DEBUG   ] Starting the watch-stream for services.v1 cluster-wide.
[2023-10-19 14:41:05,367] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-nodes] Resuming is in progress: {'metadata': {'name': 'siem-kafka-zooke
eper-nodes', 'namespace': 'siem-strimzi', 'uid': '46b9c17a-9189-49be-ab89-148451b1fdaf', 'resourceVersion': '2262892', 'creationTimestamp': '2023-10-13T12:32:40Z',
'labels': {'app.kubernetes.io/instance': 'siem-kafka', 'app.kubernetes.io/managed-by': 'strimzi-cluster-operator', 'app.kubernetes.io/name': 'zookeeper', 'app.kuber
netes.io/part-of': 'strimzi-siem-kafka', 'strimzi.io/cluster': 'siem-kafka', 'strimzi.io/component-type': 'zookeeper', 'strimzi.io/kind': 'Kafka', 'strimzi.io/name'
: 'siem-kafka-zookeeper'}, 'annotations': {'kopf.zalando.org/last-handled-configuration': '{"spec":{"ports":[{"name":"tcp-clients","protocol":"TCP","port":2181,"tar
getPort":2181},{"name":"tcp-clustering","protocol":"TCP","port":2888,"targetPort":2888},{"name":"tcp-election","protocol":"TCP","port":3888,"targetPort":3888}],"sel
ector":{"strimzi.io/cluster":"siem-kafka","strimzi.io/kind":"Kafka","strimzi.io/name":"siem-kafka-zookeeper"},"clusterIP":"None","clusterIPs":["None"],"type":"Clust
erIP","sessionAffinity":"None","publishNotReadyAddresses":true,"ipFamilies":["IPv4"],"ipFamilyPolicy":"SingleStack","internalTrafficPolicy":"Cluster"},"metadata":{"
labels":{"app.kubernetes.io/instance":"siem-kafka","app.kubernetes.io/managed-by":"strimzi-cluster-operator","app.kubernetes.io/name":"zookeeper","app.kubernetes.io
/part-of":"strimzi-siem-kafka","strimzi.io/cluster":"siem-kafka","strimzi.io/component-type":"zookeeper","strimzi.io/kind":"Kafka","strimzi.io/name":"siem-kafka-zoo
keeper"}}}\n'}, 'ownerReferences': [{'apiVersion': 'kafka.strimzi.io/v1beta2', 'kind': 'Kafka', 'name': 'siem-kafka', 'uid': 'c4e5239a-021a-436f-b4c9-281948bdb963',
 'controller': False, 'blockOwnerDeletion': False}], 'finalizers': ['kopf.zalando.org/KopfFinalizerMarker'], 'managedFields': [{'manager': 'strimzi-cluster-operator
', 'operation': 'Update', 'apiVersion': 'v1', 'time': '2023-10-13T12:32:40Z', 'fieldsType': 'FieldsV1', 'fieldsV1': {'f:metadata': {'f:labels': {'.': {}, 'f:app.kub
ernetes.io/instance': {}, 'f:app.kubernetes.io/managed-by': {}, 'f:app.kubernetes.io/name': {}, 'f:app.kubernetes.io/part-of': {}, 'f:strimzi.io/cluster': {}, 'f:st
rimzi.io/component-type': {}, 'f:strimzi.io/kind': {}, 'f:strimzi.io/name': {}}, 'f:ownerReferences': {'.': {}, 'k:{"uid":"c4e5239a-021a-436f-b4c9-281948bdb963"}':
{}}}, 'f:spec': {'f:clusterIP': {}, 'f:internalTrafficPolicy': {}, 'f:ports': {'.': {}, 'k:{"port":2181,"protocol":"TCP"}': {'.': {}, 'f:name': {}, 'f:port': {}, 'f
:protocol': {}, 'f:targetPort': {}}, 'k:{"port":2888,"protocol":"TCP"}': {'.': {}, 'f:name': {}, 'f:port': {}, 'f:protocol': {}, 'f:targetPort': {}}, 'k:{"port":388
8,"protocol":"TCP"}': {'.': {}, 'f:name': {}, 'f:port': {}, 'f:protocol': {}, 'f:targetPort': {}}}, 'f:publishNotReadyAddresses': {}, 'f:selector': {}, 'f:sessionAf
finity': {}, 'f:type': {}}}}, {'manager': 'kopf', 'operation': 'Update', 'apiVersion': 'v1', 'time': '2023-10-19T14:39:05Z', 'fieldsType': 'FieldsV1', 'fieldsV1': {
'f:metadata': {'f:annotations': {'.': {}, 'f:kopf.zalando.org/last-handled-configuration': {}}, 'f:finalizers': {'.': {}, 'v:"kopf.zalando.org/KopfFinalizerMarker"'
: {}}}}}]}, 'spec': {'ports': [{'name': 'tcp-clients', 'protocol': 'TCP', 'port': 2181, 'targetPort': 2181}, {'name': 'tcp-clustering', 'protocol': 'TCP', 'port': 2
888, 'targetPort': 2888}, {'name': 'tcp-election', 'protocol': 'TCP', 'port': 3888, 'targetPort': 3888}], 'selector': {'strimzi.io/cluster': 'siem-kafka', 'strimzi.io/kind': 'Kafka', 'strimzi.io/name': 'siem-kafka-zookeeper'}, 'clusterIP': 'None', 'clusterIPs': ['None'], 'type': 'ClusterIP', 'sessionAffinity': 'None', 'publish
NotReadyAddresses': True, 'ipFamilies': ['IPv4'], 'ipFamilyPolicy': 'SingleStack', 'internalTrafficPolicy': 'Cluster'}, 'status': {'loadBalancer': {}}, 'kind': 'Ser
vice', 'apiVersion': 'v1'}
[2023-10-19 14:41:05,367] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-nodes] Handling cycle is finished, waiting for new changes.

# Resumes for all services in cluster
# Then gets stuck with a few services

[2023-10-19 14:43:05,236] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-client] Adding the finalizer, thus preventing the actual deletion.
[2023-10-19 14:43:05,237] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-client] Patching with: {'metadata': {'finalizers': ['kopf.zalando.org/K
opfFinalizerMarker']}}
[2023-10-19 14:43:05,377] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-client] Creation is in progress: {'kind': 'Service', 'apiVersion': 'v1'
, 'metadata': {'name': 'siem-kafka-zookeeper-client', 'namespace': 'siem-strimzi', 'uid': '2232dd65-a841-4e06-8cb0-92a24f0fcc87', 'resourceVersion': '2263899', 'cre
ationTimestamp': '2023-10-13T12:32:39Z', 'labels': {'app.kubernetes.io/instance': 'siem-kafka', 'app.kubernetes.io/managed-by': 'strimzi-cluster-operator', 'app.kub
ernetes.io/name': 'zookeeper', 'app.kubernetes.io/part-of': 'strimzi-siem-kafka', 'strimzi.io/cluster': 'siem-kafka', 'strimzi.io/component-type': 'zookeeper', 'str
imzi.io/kind': 'Kafka', 'strimzi.io/name': 'siem-kafka-zookeeper'}, 'ownerReferences': [{'apiVersion': 'kafka.strimzi.io/v1beta2', 'kind': 'Kafka', 'name': 'siem-ka
fka', 'uid': 'c4e5239a-021a-436f-b4c9-281948bdb963', 'controller': False, 'blockOwnerDeletion': False}], 'finalizers': ['kopf.zalando.org/KopfFinalizerMarker'], 'ma
nagedFields': [{'manager': 'strimzi-cluster-operator', 'operation': 'Update', 'apiVersion': 'v1', 'time': '2023-10-13T12:32:39Z', 'fieldsType': 'FieldsV1', 'fieldsV
1': {'f:metadata': {'f:labels': {'.': {}, 'f:app.kubernetes.io/instance': {}, 'f:app.kubernetes.io/managed-by': {}, 'f:app.kubernetes.io/name': {}, 'f:app.kubernete
s.io/part-of': {}, 'f:strimzi.io/cluster': {}, 'f:strimzi.io/component-type': {}, 'f:strimzi.io/kind': {}, 'f:strimzi.io/name': {}}, 'f:ownerReferences': {'.': {},
'k:{"uid":"c4e5239a-021a-436f-b4c9-281948bdb963"}': {}}}, 'f:spec': {'f:internalTrafficPolicy': {}, 'f:ports': {'.': {}, 'k:{"port":2181,"protocol":"TCP"}': {'.': {
}, 'f:name': {}, 'f:port': {}, 'f:protocol': {}, 'f:targetPort': {}}}, 'f:selector': {}, 'f:sessionAffinity': {}, 'f:type': {}}}}, {'manager': 'kopf', 'operation':
'Update', 'apiVersion': 'v1', 'time': '2023-10-19T14:43:05Z', 'fieldsType': 'FieldsV1', 'fieldsV1': {'f:metadata': {'f:finalizers': {'.': {}, 'v:"kopf.zalando.org/K
opfFinalizerMarker"': {}}}}}]}, 'spec': {'ports': [{'name': 'tcp-clients', 'protocol': 'TCP', 'port': 2181, 'targetPort': 2181}], 'selector': {'strimzi.io/cluster':
 'siem-kafka', 'strimzi.io/kind': 'Kafka', 'strimzi.io/name': 'siem-kafka-zookeeper'}, 'clusterIP': '10.10.18.215', 'clusterIPs': ['10.10.18.215'], 'type': 'ClusterIP
', 'sessionAffinity': 'None', 'ipFamilies': ['IPv4'], 'ipFamilyPolicy': 'SingleStack', 'internalTrafficPolicy': 'Cluster'}, 'status': {'loadBalancer': {}}}
[2023-10-19 14:43:05,377] kopf.objects         [DEBUG   ] [siem-strimzi/siem-kafka-zookeeper-client] Handler 'create_svc' is invoked.
[2023-10-19 14:43:05,379] kopf.objects         [INFO    ] [siem-strimzi/siem-kafka-zookeeper-client] Handler 'create_svc' succeeded.
[2023-10-19 14:43:05,380] kopf.objects         [INFO    ] [siem-strimzi/siem-kafka-zookeeper-client] Creation is processed: 1 succeeded; 0 failed.

Additional information

kubectl describe siem-kafka-zookeeper-client

apiVersion: v1
kind: Service
metadata:
  annotations:
    kopf.zalando.org/last-handled-configuration: |
      {"spec":{"ports":[{"name":"tcp-clients","protocol":"TCP","port":2181,"targetPort":2181}],"selector":{"strimzi.io/cluster":"siem-kafka","strimzi.io/kind":"Kafk
a","strimzi.io/name":"siem-kafka-zookeeper"},"clusterIP":"10.10.18.215","clusterIPs":["10.10.18.215"],"type":"ClusterIP","sessionAffinity":"None","ipFamilies":["IPv4"
],"ipFamilyPolicy":"SingleStack","internalTrafficPolicy":"Cluster"},"metadata":{"labels":{"app.kubernetes.io/instance":"siem-kafka","app.kubernetes.io/managed-by":"
strimzi-cluster-operator","app.kubernetes.io/name":"zookeeper","app.kubernetes.io/part-of":"strimzi-siem-kafka","strimzi.io/cluster":"siem-kafka","strimzi.io/compon
ent-type":"zookeeper","strimzi.io/kind":"Kafka","strimzi.io/name":"siem-kafka-zookeeper"}}}
  creationTimestamp: "2023-10-13T12:32:39Z"
  finalizers:
  - kopf.zalando.org/KopfFinalizerMarker
  labels:
    app.kubernetes.io/instance: siem-kafka
    app.kubernetes.io/managed-by: strimzi-cluster-operator
    app.kubernetes.io/name: zookeeper
    app.kubernetes.io/part-of: strimzi-siem-kafka
    strimzi.io/cluster: siem-kafka
    strimzi.io/component-type: zookeeper
    strimzi.io/kind: Kafka
    strimzi.io/name: siem-kafka-zookeeper
  name: siem-kafka-zookeeper-client
  namespace: siem-strimzi
  ownerReferences:
  - apiVersion: kafka.strimzi.io/v1beta2
    blockOwnerDeletion: false
    controller: false
    kind: Kafka
    name: siem-kafka
    uid: c4e5239a-021a-436f-b4c9-281948bdb963
  resourceVersion: "2264390"
  uid: 2232dd65-a841-4e06-8cb0-92a24f0fcc87
spec:
  clusterIP: 10.10.18.215
  clusterIPs:
  - 10.10.18.215
  internalTrafficPolicy: Cluster
  ipFamilies:
  - IPv4
  ipFamilyPolicy: SingleStack
  ports:
  - name: tcp-clients
    port: 2181
    protocol: TCP
    targetPort: 2181
  selector:
    strimzi.io/cluster: siem-kafka
    strimzi.io/kind: Kafka
    strimzi.io/name: siem-kafka-zookeeper
  sessionAffinity: None
  type: ClusterIP
status:
  loadBalancer: {}

michal0000000 avatar Oct 19 '23 14:10 michal0000000

Same behavior when replacing custom resource with kubectl replace.

on.create handler is triggered even if resource exists and request type of Kubernetes API call is PUT.

valen7in avatar Oct 26 '23 07:10 valen7in