java-operator-sdk icon indicating copy to clipboard operation
java-operator-sdk copied to clipboard

Reconcilation of PersistentVolumeClaim objects gives nullpointerexception

Open tonswieb opened this issue 2 years ago • 5 comments

Bug Report

What did you do?

Create a reconciler for io.fabric8.kubernetes.api.model.PersistentVolumeClaim without any additional logic using the Quarkus based deployment.

package nl.finalist.ai;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import io.fabric8.kubernetes.api.model.PersistentVolumeClaim;
import io.javaoperatorsdk.operator.api.reconciler.Context;
import io.javaoperatorsdk.operator.api.reconciler.Reconciler;
import io.javaoperatorsdk.operator.api.reconciler.UpdateControl;

public class PersistenVolumeClaimReconciler implements Reconciler<PersistentVolumeClaim> {

	public static final Logger LOGGER = LoggerFactory.getLogger(PersistenVolumeClaimReconciler.class);
	
	@Override
	public UpdateControl<PersistentVolumeClaim> reconcile(PersistentVolumeClaim resource,
			Context<PersistentVolumeClaim> context) {
		
		LOGGER.info("Reconcile {} in {}",resource.getMetadata().getName(), resource.getMetadata().getNamespace());
		return UpdateControl.noUpdate();
	}
}

What did you expect to see?

I would expect this reconciler to startup without any errors in the log.

What did you see instead? Under which circumstances?

Instead I get an exception for each PVC that is present in the namespace I have registered when the reconciler is being started.

2022-05-11 09:03:00,013 INFO  [io.quarkus] (main) amq-operator 1.0.0-SNAPSHOT native (powered by Quarkus 2.8.1.Final) started in 0.045s. Listening on: http://0.0.0.0:8080
2022-05-11 09:03:00,013 INFO  [io.quarkus] (main) Profile prod activated.
2022-05-11 09:03:00,013 INFO  [io.quarkus] (main) Installed features: [cdi, kubernetes, kubernetes-client, openshift-client, operator-sdk, smallrye-context-propagation, smallrye-health, vertx]
2022-05-11 09:03:00,015 INFO  [io.qua.ope.run.OperatorProducer] (main) Quarkus Java Operator SDK extension 4.0.0.Beta2-SNAPSHOT (commit: 4ed7257 on branch: main) built on Tue May 10 15:53:07 GMT 2022
2022-05-11 09:03:00,016 INFO  [io.jav.ope.Operator] (main) Registered reconciler: 'persistenvolumeclaimreconciler' for resource: 'class io.fabric8.kubernetes.api.model.PersistentVolumeClaim' for namespace(s): [tst-esb]
2022-05-11 09:03:00,016 INFO  [io.jav.ope.Operator] (main) Operator SDK 3.0.1-SNAPSHOT (commit: b770d4d) built on Tue May 10 14:46:16 GMT 2022 starting...
2022-05-11 09:03:00,016 INFO  [io.jav.ope.Operator] (main) Client version: 5.12.2
2022-05-11 09:03:00,016 INFO  [io.jav.ope.pro.Controller] (main) Starting 'persistenvolumeclaimreconciler' controller for reconciler: nl.finalist.ai.PersistenVolumeClaimReconciler_ClientProxy, resource: io.fabric8.kubernetes.api.model.PersistentVolumeClaim
2022-05-11 09:03:00,080 ERROR [io.fab.kub.cli.inf.cac.SharedProcessor] (main) Failed invoking io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource@2851915d event handler: null: java.lang.NullPointerException
	at io.javaoperatorsdk.operator.processing.event.ResourceID.fromResource(ResourceID.java:12)
	at io.javaoperatorsdk.operator.processing.event.source.informer.TemporaryResourceCache.removeResourceFromCache(TemporaryResourceCache.java:45)
	at io.javaoperatorsdk.operator.processing.event.source.informer.ManagedInformerEventSource.onAdd(ManagedInformerEventSource.java:44)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.onAdd(ControllerResourceEventSource.java:77)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.onAdd(ControllerResourceEventSource.java:23)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorListener$AddNotification.handle(ProcessorListener.java:96)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorListener.add(ProcessorListener.java:47)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.lambda$distribute$0(SharedProcessor.java:79)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.lambda$distribute$1(SharedProcessor.java:101)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.lambda$execute$0(SerialExecutor.java:40)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.scheduleNext(SerialExecutor.java:52)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.execute(SerialExecutor.java:46)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.distribute(SharedProcessor.java:98)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.distribute(SharedProcessor.java:79)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorStore.update(ProcessorStore.java:50)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorStore.update(ProcessorStore.java:28)
	at io.fabric8.kubernetes.client.informers.cache.Reflector.lambda$listSyncAndWatch$0(Reflector.java:85)
	at java.util.ArrayList.forEach(ArrayList.java:1541)
	at io.fabric8.kubernetes.client.informers.cache.Reflector.listSyncAndWatch(Reflector.java:82)
	at io.fabric8.kubernetes.client.informers.impl.DefaultSharedIndexInformer.run(DefaultSharedIndexInformer.java:146)
	at io.javaoperatorsdk.operator.processing.event.source.informer.InformerWrapper.start(InformerWrapper.java:36)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.util.concurrent.ConcurrentHashMap$ValueSpliterator.forEachRemaining(ConcurrentHashMap.java:3605)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290)
	at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:746)
	at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:408)
	at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:736)
	at java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:661)
	at io.javaoperatorsdk.operator.processing.event.source.informer.InformerManager.start(InformerManager.java:44)
	at io.javaoperatorsdk.operator.processing.event.source.informer.ManagedInformerEventSource.start(ManagedInformerEventSource.java:75)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.start(ControllerResourceEventSource.java:51)
	at io.javaoperatorsdk.operator.processing.event.NamedEventSource.start(NamedEventSource.java:18)
	at io.javaoperatorsdk.operator.processing.event.EventSourceManager.start(EventSourceManager.java:66)
	at io.javaoperatorsdk.operator.processing.Controller.start(Controller.java:305)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183)
	at java.util.HashMap$ValueSpliterator.forEachRemaining(HashMap.java:1693)
	at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
	at java.util.stream.ForEachOps$ForEachTask.compute(ForEachOps.java:290)
	at java.util.concurrent.CountedCompleter.exec(CountedCompleter.java:746)
	at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
	at java.util.concurrent.ForkJoinTask.doInvoke(ForkJoinTask.java:408)
	at java.util.concurrent.ForkJoinTask.invoke(ForkJoinTask.java:736)
	at java.util.stream.ForEachOps$ForEachOp.evaluateParallel(ForEachOps.java:159)
	at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateParallel(ForEachOps.java:173)
	at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:233)
	at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:497)
	at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:661)
	at io.javaoperatorsdk.operator.Operator$ControllerManager.start(Operator.java:219)
	at io.javaoperatorsdk.operator.Operator.start(Operator.java:100)
	at nl.finalist.ai.FinalistOperator.run(FinalistOperator.java:22)
	at nl.finalist.ai.FinalistOperator_ClientProxy.run(Unknown Source)
	at io.quarkus.runtime.ApplicationLifecycleManager.run(ApplicationLifecycleManager.java:124)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:67)
	at io.quarkus.runtime.Quarkus.run(Quarkus.java:41)
	at nl.finalist.ai.FinalistOperator.main(FinalistOperator.java:17)

When creating a new PVC again an exception is thrown, but the reconciler is executed normally. The following exceptions are visible in the logs.

2022-05-11 09:07:45,598 INFO  [nl.fin.ai.PersistenVolumeClaimReconciler] (EventHandler-persistenvolumeclaimreconciler) Reconcile test in tst-esb
2022-05-11 09:07:45,619 ERROR [io.fab.kub.cli.inf.cac.SharedProcessor] (OkHttp https://172.30.0.1/...) Failed invoking io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource@2851915d event handler: null: java.lang.NullPointerException
	at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilters.lambda$static$1(ResourceEventFilters.java:27)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilters.lambda$or$6(ResourceEventFilters.java:157)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilter.lambda$and$0(ResourceEventFilter.java:39)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.eventReceived(ControllerResourceEventSource.java:63)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.onUpdate(ControllerResourceEventSource.java:84)
	at io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource.onUpdate(ControllerResourceEventSource.java:23)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorListener$UpdateNotification.handle(ProcessorListener.java:85)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorListener.add(ProcessorListener.java:47)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.lambda$distribute$0(SharedProcessor.java:79)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.lambda$distribute$1(SharedProcessor.java:101)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.lambda$execute$0(SerialExecutor.java:40)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.scheduleNext(SerialExecutor.java:52)
	at io.fabric8.kubernetes.client.utils.SerialExecutor.execute(SerialExecutor.java:46)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.distribute(SharedProcessor.java:98)
	at io.fabric8.kubernetes.client.informers.cache.SharedProcessor.distribute(SharedProcessor.java:79)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorStore.update(ProcessorStore.java:47)
	at io.fabric8.kubernetes.client.informers.cache.ProcessorStore.update(ProcessorStore.java:28)
	at io.fabric8.kubernetes.client.informers.cache.Reflector$ReflectorWatcher.eventReceived(Reflector.java:148)
	at io.fabric8.kubernetes.client.informers.cache.Reflector$ReflectorWatcher.eventReceived(Reflector.java:128)
	at io.fabric8.kubernetes.client.utils.WatcherToggle.eventReceived(WatcherToggle.java:49)
	at io.fabric8.kubernetes.client.dsl.internal.AbstractWatchManager.eventReceived(AbstractWatchManager.java:203)
	at io.fabric8.kubernetes.client.dsl.internal.AbstractWatchManager.onMessage(AbstractWatchManager.java:306)
	at io.fabric8.kubernetes.client.dsl.internal.WatcherWebSocketListener.onMessage(WatcherWebSocketListener.java:68)
	at io.fabric8.kubernetes.client.okhttp.OkHttpWebSocketImpl$BuilderImpl$1.onMessage(OkHttpWebSocketImpl.java:97)
	at okhttp3.internal.ws.RealWebSocket.onReadMessage(RealWebSocket.java:322)
	at okhttp3.internal.ws.WebSocketReader.readMessageFrame(WebSocketReader.java:219)
	at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:105)
	at okhttp3.internal.ws.RealWebSocket.loopReader(RealWebSocket.java:273)
	at okhttp3.internal.ws.RealWebSocket$1.onResponse(RealWebSocket.java:209)
	at okhttp3.RealCall$AsyncCall.execute(RealCall.java:174)
	at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.lang.Thread.run(Thread.java:829)
	at com.oracle.svm.core.thread.JavaThreads.threadStartRoutine(JavaThreads.java:597)
	at com.oracle.svm.core.posix.thread.PosixJavaThreads.pthreadStartRoutine(PosixJavaThreads.java:194)

Environment

Kubernetes cluster type: Openshift v4.8.33

$ Mention java-operator-sdk version from pom.xml file I tried the following versions:

    <dependency>
      <groupId>io.quarkiverse.operatorsdk</groupId>
      <artifactId>quarkus-operator-sdk</artifactId>
      <version>4.0.0.Beta2-SNAPSHOT</version>
<!--      <version>3.0.7</version>
      <version>4.0.0.Beta1</version> -->
    </dependency>

$ java -version It is a Quarkus native build based on GraalVM 22.0.0.2 Java 11 CE

$ kubectl version Client Version: version.Info{Major:"1", Minor:"22", GitVersion:"v1.22.5", GitCommit:"5c99e2ac2ff9a3c549d9ca665e7bc05a3e18f07e", GitTreeState:"clean", BuildDate:"2021-12-16T08:38:33Z", GoVersion:"go1.16.12", Compiler:"gc", Platform:"darwin/arm64"} Server Version: version.Info{Major:"1", Minor:"21", GitVersion:"v1.21.8+ed4d8fd", GitCommit:"f7310cc5b1c14454dcd067838ca8407e9da13a26", GitTreeState:"clean", BuildDate:"2022-04-19T21:14:01Z", GoVersion:"go1.16.12", Compiler:"gc", Platform:"linux/amd64"}

Possible Solution

Additional context

It seems a NullPointer is thrown by the Fabric8 Kubernetes Client when retrieving the metadata.name field from the resource. All the PVC have the metadata.name field populated so that is strange. I assume it is a mandatory field anyway.

I have given the operator the following authorizations:

  • apiGroups:
    • '' resources:
    • persistentvolumeclaims verbs:
    • get
    • list
    • watch
  • apiGroups:
    • apiextensions.k8s.io resources:
    • customresourcedefinitions verbs:
    • get
    • list

tonswieb avatar May 11 '22 09:05 tonswieb

thx @tonswieb we will take a look, it's quite strange, it look like the resource does not have metadata (from a quick look on the logs), will dig into it little later.

csviri avatar May 11 '22 11:05 csviri

Do you have the same issue running in JVM mode?

metacosm avatar May 11 '22 13:05 metacosm

I just checked. I don't experience this issue when running in JVM mode.


Van: Chris Laprun @.> Verzonden: woensdag 11 mei 2022 15:15 Aan: java-operator-sdk/java-operator-sdk @.> CC: Ton Swieb @.>; Mention @.> Onderwerp: Re: [java-operator-sdk/java-operator-sdk] Reconcilation of PersistentVolumeClaim objects gives nullpointerexception (Issue #1208)

Do you have the same issue running in JVM mode?

— Reply to this email directly, view it on GitHubhttps://github.com/java-operator-sdk/java-operator-sdk/issues/1208#issuecomment-1123748328, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AAGDNUK4AAI6DCKHVAEU6NLVJOXHPANCNFSM5VUIIGCA. You are receiving this because you were mentioned.Message ID: @.***>

[http://footer.finalist.nl/Finalist_banner_2020.png]

tonswieb avatar May 11 '22 13:05 tonswieb

I am running into a similar issue also in JVM mode when reconciling secrets. We are running on an AKS cluster and there is one secret provided by Azure that looks like this:

apiVersion: v1
data:
  token: [...]
kind: Secret
metadata:
  creationTimestamp: "2022-05-25T06:34:59Z"
  finalizers:
  - secrets.javaoperatorsdk.io/finalizer
  name: omsagent-aad-msi-token
  namespace: kube-system
  resourceVersion: "106136737"
  uid: 768367e5-a910-4127-91e0-3acc10cb3920
type: Opaque

And it results in the same exception like above:

2022-05-25 09:54:58,950 DEBUG [io.jav.ope.pro.eve.sou.con.ControllerResourceEventSource] (OkHttp https://tst-1f074424.hcp.westeurope.azmk8s.io/...) Event received for resource: omsagent-aad-msi-token
2022-05-25 09:54:58,962 ERROR [io.fab.kub.cli.inf.cac.SharedProcessor] (OkHttp https://****.hcp.westeurope.azmk8s.io/...) Failed invoking io.javaoperatorsdk.operator.processing.event.source.controller.ControllerResourceEventSource@3a7732ea event handler: null: java.lang.NullPointerException
        at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilters.lambda$static$1(ResourceEventFilters.java:27)
        at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilters.lambda$or$6(ResourceEventFilters.java:157)
        at io.javaoperatorsdk.operator.processing.event.source.controller.ResourceEventFilter.lambda$and$0(ResourceEventFilter.java:39)

(this is still on quarkus extension 3.0.7 / OSDK 2.1.4)

flo-02-mu avatar May 25 '22 08:05 flo-02-mu

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

github-actions[bot] avatar Jul 25 '22 03:07 github-actions[bot]

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 14 days.

github-actions[bot] avatar Sep 24 '22 04:09 github-actions[bot]

This issue was closed because it has been stalled for 14 days with no activity.

github-actions[bot] avatar Oct 09 '22 03:10 github-actions[bot]

I don't know. I only tried the native mode up to now. I will give it a try.


Van: Chris Laprun @.> Verzonden: woensdag 11 mei 2022 15:15 Aan: java-operator-sdk/java-operator-sdk @.> CC: Ton Swieb @.>; Mention @.> Onderwerp: Re: [java-operator-sdk/java-operator-sdk] Reconcilation of PersistentVolumeClaim objects gives nullpointerexception (Issue #1208)

Do you have the same issue running in JVM mode?

— Reply to this email directly, view it on GitHubhttps://github.com/java-operator-sdk/java-operator-sdk/issues/1208#issuecomment-1123748328, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AAGDNUK4AAI6DCKHVAEU6NLVJOXHPANCNFSM5VUIIGCA. You are receiving this because you were mentioned.Message ID: @.***>

[http://footer.finalist.nl/Finalist_banner_2020.png]

tonswieb avatar Oct 11 '22 07:10 tonswieb