Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Operator shutting down after one minute #202

Open
heruan opened this issue Jan 29, 2025 · 13 comments
Open

Operator shutting down after one minute #202

heruan opened this issue Jan 29, 2025 · 13 comments

Comments

@heruan
Copy link

heruan commented Jan 29, 2025

I'm trying to build a simple operator, right now it is just like this:

@Informer
public class AppController implements Reconciler<App> {

    @Override
    public UpdateControl<App> reconcile(App app, Context<App> context) {
        System.out.println("RECONCILE RUNNING");
        return UpdateControl.noUpdate();
    }
}

When I start the app, after one minute it shuts down:

2025-01-29T18:07:41.176+01:00  INFO 92570 --- [           main] c.v.c.operator.OperatorApplication       : Started OperatorApplication in 1.203 seconds (process running for 1.381)
2025-01-29T18:07:41.177+01:00  INFO 92570 --- [           main] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 (commit: dd40cbc) built on Fri Dec 06 12:07:51 CET 2024 starting...
2025-01-29T18:07:41.180+01:00  INFO 92570 --- [           main] io.javaoperatorsdk.operator.Operator     : Client version: 7.0.0
2025-01-29T18:07:41.181+01:00  INFO 92570 --- [: appcontroller] i.j.operator.processing.Controller       : Starting 'appcontroller' controller for reconciler: com.vaadin.controlcenter.operator.AppController, resource: com.vaadin.controlcenter.operator.App
2025-01-29T18:07:41.771+01:00  INFO 92570 --- [: appcontroller] i.j.operator.processing.Controller       : 'appcontroller' controller started
2025-01-29T18:08:41.777+01:00  INFO 92570 --- [ionShutdownHook] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 is shutting down...

I still have no App custom resources created, I just noticed it shuts down for some reason. Is this expected?

@csviri
Copy link
Contributor

csviri commented Jan 29, 2025

Hi @heruan , no it is not, if you could share your code we can take a look.

Aren't you definening some health probes? My guess would be k8s is shutting it down.

@heruan
Copy link
Author

heruan commented Jan 29, 2025

No probes. I tested running from the IDE, still shuts down. Debugging looks like it's Spring shutting down and closing the operator, but why would Spring shut down once the operator is started?

Minimum reproducible code:

plugins {
    id("java")
    id("org.springframework.boot") version "3.4.2"
    id("io.spring.dependency-management") version "1.1.7"
}

dependencies {
    implementation("org.springframework.boot:spring-boot-starter-logging")
    implementation("io.javaoperatorsdk:operator-framework-spring-boot-starter:6.0.0-beta2")
}
package test;

import io.fabric8.kubernetes.api.model.KubernetesResource;
import io.fabric8.kubernetes.api.model.Namespaced;
import io.fabric8.kubernetes.client.CustomResource;
import io.fabric8.kubernetes.model.annotation.Group;
import io.fabric8.kubernetes.model.annotation.Version;

@Group("com.vaadin")
@Version("v1")
public class App extends CustomResource<AppSpec, AppStatus> implements
        Namespaced {

    public static class AppSpec implements KubernetesResource {
    }

    public static class AppStatus implements KubernetesResource {
    }
}
package test;

import io.javaoperatorsdk.operator.api.config.informer.Informer;
import io.javaoperatorsdk.operator.api.reconciler.Context;
import io.javaoperatorsdk.operator.api.reconciler.Reconciler;
import io.javaoperatorsdk.operator.api.reconciler.UpdateControl;
import org.springframework.stereotype.Component;

@Informer
@Component
public class AppController implements Reconciler<App> {

    @Override
    public UpdateControl<App> reconcile(App app, Context<App> context) {
        System.out.println("RECONCILE RUNNING");
        return UpdateControl.noUpdate();
    }
}
package test;

import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;

@SpringBootApplication
public class OperatorApplication {

    public static void main(String... args) {
        SpringApplication.run(OperatorApplication.class, args);
    }
}

Shutdown happens both running with gradle bootRun or building the image with gradle bootBuildImage and deploying to the cluster.

@csviri
Copy link
Contributor

csviri commented Jan 30, 2025

@heruan how are you generating the CRD? or you apply that manually? can you please that too pls

@heruan
Copy link
Author

heruan commented Jan 30, 2025

The CRD is generated by Fabric8:

# Generated by Fabric8 CRDGenerator, manual edits might get overwritten!
apiVersion: "apiextensions.k8s.io/v1"
kind: "CustomResourceDefinition"
metadata:
  name: "apps.com.vaadin"
spec:
  group: "com.vaadin"
  names:
    kind: "App"
    plural: "apps"
    singular: "app"
  scope: "Namespaced"
  versions:
  - name: "v1"
    schema:
      openAPIV3Schema:
        properties:
          spec:
            type: "object"
          status:
            type: "object"
        type: "object"
    served: true
    storage: true
    subresources:
      status: {}

@heruan
Copy link
Author

heruan commented Jan 30, 2025

Tested with 5.6.0 and it doesn't happen, so I'd assume the cause is somewhere in v5.6.0...v6.0.0-beta2

@heruan
Copy link
Author

heruan commented Jan 30, 2025

Shutdown happens only with JOSDK 5.0.0-beta1/RC1, downgrading to 4.9.7 works (still using JOSDK Starter 6.0.0-beta2).

Log with JOSDK 5.0.0-beta1 on Spring Boot 3.4.2:

 :: Spring Boot ::                (v3.4.2)

2025-01-30T17:52:32.087+01:00  INFO 20215 --- [           main] test.OperatorApplication                 : Starting OperatorApplication using Java 23.0.2 with PID 20215 (/Users/heruan/Workspaces/gradle/operator-test/build/classes/java/main started by heruan in /Users/heruan/Workspaces/gradle/operator-test)
2025-01-30T17:52:32.089+01:00  INFO 20215 --- [           main] test.OperatorApplication                 : No active profile set, falling back to 1 default profile: "default"
2025-01-30T17:52:32.762+01:00  WARN 20215 --- [           main] i.f.k.client.utils.HttpClientUtils       : The following httpclient factories were detected on your classpath: [io.fabric8.kubernetes.client.jdkhttp.JdkHttpClientFactory, io.fabric8.kubernetes.client.vertx.VertxHttpClientFactory], multiple of which had the same priority (0) so one was chosen randomly. You should exclude dependencies that aren't needed or use an explicit association of the HttpClient.Factory.
2025-01-30T17:52:32.944+01:00  WARN 20215 --- [           main] ault ConfigurationService implementation : Configuration for reconciler 'appcontroller' was not found. Known reconcilers: None.
2025-01-30T17:52:32.948+01:00  INFO 20215 --- [           main] ault ConfigurationService implementation : Created configuration for reconciler test.AppController with name appcontroller
2025-01-30T17:52:32.956+01:00  INFO 20215 --- [           main] io.javaoperatorsdk.operator.Operator     : Registered reconciler: 'appcontroller' for resource: 'class test.App' for namespace(s): [all namespaces]
2025-01-30T17:52:33.001+01:00  INFO 20215 --- [           main] test.OperatorApplication                 : Started OperatorApplication in 1.072 seconds (process running for 1.609)
2025-01-30T17:52:33.003+01:00  INFO 20215 --- [           main] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 (commit: dd40cbc) built on Fri Dec 06 12:07:51 CET 2024 starting...
2025-01-30T17:52:33.003+01:00  INFO 20215 --- [           main] io.javaoperatorsdk.operator.Operator     : Client version: 7.0.0
2025-01-30T17:52:33.004+01:00  INFO 20215 --- [: appcontroller] i.j.operator.processing.Controller       : Starting 'appcontroller' controller for reconciler: test.AppController, resource: test.App
2025-01-30T17:52:33.256+01:00  INFO 20215 --- [: appcontroller] i.j.operator.processing.Controller       : 'appcontroller' controller started
2025-01-30T17:53:33.833+01:00  INFO 20215 --- [ionShutdownHook] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 is shutting down...

Log with JOSDK downgraded to 4.9.7 (still Spring Boot 3.4.2 and JOSDK Starter 6.0.0-beta2):

 :: Spring Boot ::                (v3.4.2)

2025-01-30T17:49:00.141+01:00  INFO 20157 --- [           main] test.OperatorApplication                 : Starting OperatorApplication using Java 23.0.2 with PID 20157 (/Users/heruan/Workspaces/gradle/operator-test/build/classes/java/main started by heruan in /Users/heruan/Workspaces/gradle/operator-test)
2025-01-30T17:49:00.143+01:00  INFO 20157 --- [           main] test.OperatorApplication                 : No active profile set, falling back to 1 default profile: "default"
2025-01-30T17:49:01.116+01:00  WARN 20157 --- [           main] ault ConfigurationService implementation : Configuration for reconciler 'appcontroller' was not found. Known reconcilers: None.
2025-01-30T17:49:01.119+01:00  INFO 20157 --- [           main] ault ConfigurationService implementation : Created configuration for reconciler test.AppController with name appcontroller
2025-01-30T17:49:01.126+01:00  INFO 20157 --- [           main] io.javaoperatorsdk.operator.Operator     : Registered reconciler: 'appcontroller' for resource: 'class test.App' for namespace(s): [all namespaces]
2025-01-30T17:49:01.165+01:00  INFO 20157 --- [           main] test.OperatorApplication                 : Started OperatorApplication in 1.206 seconds (process running for 1.766)
2025-01-30T17:49:10.690+01:00  INFO 20157 --- [           main] io.javaoperatorsdk.operator.Operator     : Operator SDK 4.9.7 (commit: 1f6cf2c) built on Thu Nov 21 08:58:49 CET 2024 starting...
2025-01-30T17:49:10.690+01:00  INFO 20157 --- [           main] io.javaoperatorsdk.operator.Operator     : Client version: 7.0.0
2025-01-30T17:49:10.692+01:00  INFO 20157 --- [: appcontroller] i.j.operator.processing.Controller       : Starting 'appcontroller' controller for reconciler: test.AppController, resource: test.App
2025-01-30T17:49:11.033+01:00  INFO 20157 --- [: appcontroller] i.j.operator.processing.Controller       : 'appcontroller' controller started

For some reason the SpringApplicationShutdownHook triggers after 60s with JOSDK 5.0.0 but not with JOSDK 4.9.7.

Not sure if this warning might be relevant:

2025-01-30T17:52:32.762+01:00  WARN 20215 --- [           main] i.f.k.client.utils.HttpClientUtils       : The following httpclient factories were detected on your classpath: [io.fabric8.kubernetes.client.jdkhttp.JdkHttpClientFactory, io.fabric8.kubernetes.client.vertx.VertxHttpClientFactory], multiple of which had the same priority (0) so one was chosen randomly. You should exclude dependencies that aren't needed or use an explicit association of the HttpClient.Factory.

@csviri have you been able to replicate this?

@csviri
Copy link
Contributor

csviri commented Jan 30, 2025

not yet, hope will get to it tomorrow

@heruan
Copy link
Author

heruan commented Jan 31, 2025

Run with logs at TRACE level, put MARKER between start and shutdown.

2025-01-31T08:40:49.095+01:00  INFO 37050 --- [           main] test.OperatorApplication                 : Started OperatorApplication in 1.045 seconds (process running for 1.304)
2025-01-31T08:40:49.096+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2025-01-31T08:40:49.096+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2025-01-31T08:40:49.096+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'applicationAvailability'
2025-01-31T08:40:49.096+01:00 DEBUG 37050 --- [           main] o.s.b.a.ApplicationAvailabilityBean      : Application availability state LivenessState changed to CORRECT
2025-01-31T08:40:49.097+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2025-01-31T08:40:49.097+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'operatorStarter'
2025-01-31T08:40:49.097+01:00 DEBUG 37050 --- [           main] i.j.o.springboot.starter.CRDApplier      : Not searching for CRDs to apply
2025-01-31T08:40:49.097+01:00  INFO 37050 --- [           main] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 (commit: dd40cbc) built on Fri Dec 06 12:07:51 CET 2024 starting...
2025-01-31T08:40:49.097+01:00  INFO 37050 --- [           main] io.javaoperatorsdk.operator.Operator     : Client version: 7.0.0
2025-01-31T08:40:49.097+01:00  INFO 37050 --- [: appcontroller] i.j.operator.processing.Controller       : Starting 'appcontroller' controller for reconciler: test.AppController, resource: test.App
2025-01-31T08:40:49.279+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.event.EventSourceManager         : Starting event source ControllerResourceEventSource for class test.App
2025-01-31T08:40:49.284+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.e.s.informer.InformerManager     : Registered InformerManager [apps.com.vaadin.test/v1] watching: [JOSDK_ALL_NAMESPACES] -> InformerWrapper [apps.com.vaadin.test/v1] (com.vaadin.test/v1/apps) for any namespace
2025-01-31T08:40:49.285+01:00 DEBUG 37050 --- [din.test/v1] 47] i.j.o.p.e.s.informer.InformerWrapper     : Starting informer for namespace: JOSDK_ALL_NAMESPACES resource: App
2025-01-31T08:40:49.293+01:00 TRACE 37050 --- [din.test/v1] 47] i.j.o.p.e.s.informer.InformerWrapper     : Waiting informer to start namespace: JOSDK_ALL_NAMESPACES resource: App
2025-01-31T08:40:49.324+01:00 DEBUG 37050 --- [din.test/v1] 47] i.j.o.p.e.s.informer.InformerWrapper     : Started informer for namespace: JOSDK_ALL_NAMESPACES resource: App
2025-01-31T08:40:49.324+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.event.EventSourceManager         : Started event source ControllerResourceEventSource for class test.App
2025-01-31T08:40:49.325+01:00 DEBUG 37050 --- [imerEventSource] i.j.o.p.event.EventSourceManager         : Starting event source RetryAndRescheduleTimerEventSource for class java.lang.Void
2025-01-31T08:40:49.325+01:00 DEBUG 37050 --- [imerEventSource] i.j.o.p.event.EventSourceManager         : Started event source RetryAndRescheduleTimerEventSource for class java.lang.Void
2025-01-31T08:40:49.325+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.processing.event.EventProcessor    : Starting event processor: io.javaoperatorsdk.operator.processing.event.EventProcessor@6fdd53ff
2025-01-31T08:40:49.325+01:00  INFO 37050 --- [: appcontroller] i.j.operator.processing.Controller       : 'appcontroller' controller started
2025-01-31T08:40:49.326+01:00 TRACE 37050 --- [           main] o.s.c.e.ApplicationListenerMethodAdapter : No result object given - no result to handle
2025-01-31T08:40:49.326+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2025-01-31T08:40:49.326+01:00 TRACE 37050 --- [           main] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'applicationAvailability'
2025-01-31T08:40:49.326+01:00 DEBUG 37050 --- [           main] o.s.b.a.ApplicationAvailabilityBean      : Application availability state ReadinessState changed to ACCEPTING_TRAFFIC
==================================================== MARKER ====================================================
2025-01-31T08:41:49.329+01:00 DEBUG 37050 --- [ionShutdownHook] s.c.a.AnnotationConfigApplicationContext : Closing org.springframework.context.annotation.AnnotationConfigApplicationContext@488eb7f2, started on Fri Jan 31 08:40:48 CET 2025
2025-01-31T08:41:49.329+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springApplicationAdminRegistrar'
2025-01-31T08:41:49.330+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'lifecycleProcessor'
2025-01-31T08:41:49.330+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Returning cached instance of singleton bean 'springBootLoggingLifecycle'
2025-01-31T08:41:49.330+01:00 DEBUG 37050 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Stopping beans in phase -2147483647
2025-01-31T08:41:49.331+01:00 TRACE 37050 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Asking bean 'springBootLoggingLifecycle' of type [org.springframework.boot.context.logging.LoggingApplicationListener$Lifecycle] to stop
2025-01-31T08:41:49.331+01:00 DEBUG 37050 --- [ionShutdownHook] o.s.c.support.DefaultLifecycleProcessor  : Bean 'springBootLoggingLifecycle' completed its stop procedure
2025-01-31T08:41:49.331+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@7997b197: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.event.internalEventListenerProcessor,org.springframework.context.event.internalEventListenerFactory,operatorApplication,org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory,appController,org.springframework.boot.autoconfigure.AutoConfigurationPackages,org.springframework.boot.autoconfigure.context.PropertyPlaceholderAutoConfiguration,propertySourcesPlaceholderConfigurer,io.javaoperatorsdk.operator.springboot.starter.OperatorAutoConfiguration,kubernetesClient,resourceClassResolver,disabledCrdApplier,operatorStarter,operator,reconcilerRegisterer,compositeConfigurationServiceOverrider,defaultConfigServiceOverrider,reconciliationExecutorService,metrics,getClientConfiguration,org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor,org.springframework.boot.context.internalConfigurationPropertiesBinder,org.springframework.boot.context.properties.BoundConfigurationProperties,org.springframework.boot.context.properties.EnableConfigurationPropertiesRegistrar.methodValidationExcludeFilter,javaoperatorsdk-io.javaoperatorsdk.operator.springboot.starter.OperatorConfigurationProperties,org.springframework.boot.autoconfigure.jmx.JmxAutoConfiguration,mbeanExporter,objectNamingStrategy,mbeanServer,spring.jmx-org.springframework.boot.autoconfigure.jmx.JmxProperties,org.springframework.boot.autoconfigure.admin.SpringApplicationAdminJmxAutoConfiguration,springApplicationAdminRegistrar,org.springframework.boot.autoconfigure.aop.AopAutoConfiguration$ClassProxyingConfiguration,forceAutoProxyCreatorToUseClassProxying,org.springframework.boot.autoconfigure.aop.AopAutoConfiguration,org.springframework.boot.autoconfigure.availability.ApplicationAvailabilityAutoConfiguration,applicationAvailability,org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration$JacksonMixinConfiguration,jsonMixinModuleEntries,jsonMixinModule,org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration,jsonComponentModule,org.springframework.boot.autoconfigure.context.ConfigurationPropertiesAutoConfiguration,org.springframework.boot.autoconfigure.context.LifecycleAutoConfiguration,lifecycleProcessor,spring.lifecycle-org.springframework.boot.autoconfigure.context.LifecycleProperties,org.springframework.boot.autoconfigure.info.ProjectInfoAutoConfiguration,spring.info-org.springframework.boot.autoconfigure.info.ProjectInfoProperties,org.springframework.boot.autoconfigure.netty.NettyAutoConfiguration,spring.netty-org.springframework.boot.autoconfigure.netty.NettyProperties,org.springframework.boot.autoconfigure.sql.init.SqlInitializationAutoConfiguration,spring.sql.init-org.springframework.boot.autoconfigure.sql.init.SqlInitializationProperties,org.springframework.boot.sql.init.dependency.DatabaseInitializationDependencyConfigurer$DependsOnDatabaseInitializationPostProcessor,org.springframework.boot.autoconfigure.ssl.SslAutoConfiguration,fileWatcher,sslPropertiesSslBundleRegistrar,sslBundleRegistry,spring.ssl-org.springframework.boot.autoconfigure.ssl.SslProperties,org.springframework.boot.autoconfigure.task.TaskExecutorConfigurations$ThreadPoolTaskExecutorBuilderConfiguration,threadPoolTaskExecutorBuilder,org.springframework.boot.autoconfigure.task.TaskExecutorConfigurations$SimpleAsyncTaskExecutorBuilderConfiguration,simpleAsyncTaskExecutorBuilder,org.springframework.boot.autoconfigure.task.TaskExecutionAutoConfiguration,spring.task.execution-org.springframework.boot.autoconfigure.task.TaskExecutionProperties,org.springframework.boot.autoconfigure.task.TaskSchedulingConfigurations$ThreadPoolTaskSchedulerBuilderConfiguration,threadPoolTaskSchedulerBuilder,org.springframework.boot.autoconfigure.task.TaskSchedulingConfigurations$SimpleAsyncTaskSchedulerBuilderConfiguration,simpleAsyncTaskSchedulerBuilder,org.springframework.boot.autoconfigure.task.TaskSchedulingAutoConfiguration,spring.task.scheduling-org.springframework.boot.autoconfigure.task.TaskSchedulingProperties,org.springframework.aop.config.internalAutoProxyCreator]; root of factory hierarchy
2025-01-31T08:41:49.332+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'fileWatcher': [sslPropertiesSslBundleRegistrar]
2025-01-31T08:41:49.332+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking close() on bean with name 'fileWatcher'
2025-01-31T08:41:49.332+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking destroy() on bean with name 'springApplicationAdminRegistrar'
2025-01-31T08:41:49.332+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking destroy() on bean with name 'mbeanExporter'
2025-01-31T08:41:49.332+01:00 DEBUG 37050 --- [ionShutdownHook] o.s.j.e.a.AnnotationMBeanExporter        : Unregistering JMX-exposed beans on shutdown
2025-01-31T08:41:49.333+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking close() on bean with name 'reconciliationExecutorService'
2025-01-31T08:41:49.333+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'operator': [operatorStarter]
2025-01-31T08:41:49.333+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking custom destroy method 'stop' on bean with name 'operator': public void io.javaoperatorsdk.operator.Operator.stop() throws io.javaoperatorsdk.operator.OperatorException
2025-01-31T08:41:49.333+01:00  INFO 37050 --- [ionShutdownHook] io.javaoperatorsdk.operator.Operator     : Operator SDK 5.0.0-beta1 is shutting down...
2025-01-31T08:41:49.334+01:00 DEBUG 37050 --- [: appcontroller] i.j.operator.ControllerManager           : closing 'appcontroller' Controller
2025-01-31T08:41:49.334+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.event.EventSourceManager         : Stopping event source ControllerResourceEventSource for class test.App
2025-01-31T08:41:49.334+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.e.s.informer.InformerManager     : Stopping informer for namespace: JOSDK_ALL_NAMESPACES -> InformerWrapper [apps.com.vaadin.test/v1] (com.vaadin.test/v1/apps)
2025-01-31T08:41:49.339+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.api.config.ConfigurationService    : Informer stopped: com.vaadin.test/v1/apps. Has synced: true, Error: null. This can happen as a result of stopping the controller, or due to an error on startup.See also stopOnInformerErrorDuringStartup configuration.
2025-01-31T08:41:49.339+01:00 DEBUG 37050 --- [: appcontroller] i.j.o.p.event.EventSourceManager         : Stopped event source ControllerResourceEventSource for class test.App
2025-01-31T08:41:49.339+01:00 DEBUG 37050 --- [imerEventSource] i.j.o.p.event.EventSourceManager         : Stopping event source RetryAndRescheduleTimerEventSource for class java.lang.Void
2025-01-31T08:41:49.339+01:00 DEBUG 37050 --- [imerEventSource] i.j.o.p.event.EventSourceManager         : Stopped event source RetryAndRescheduleTimerEventSource for class java.lang.Void
2025-01-31T08:41:49.340+01:00 DEBUG 37050 --- [ionShutdownHook] i.j.o.api.config.ExecutorServiceManager  : Closing executor
2025-01-31T08:41:49.341+01:00 DEBUG 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Custom destroy method 'stop' on bean with name 'operator' completed
2025-01-31T08:41:49.341+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'kubernetesClient': [defaultConfigServiceOverrider]
2025-01-31T08:41:49.341+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'defaultConfigServiceOverrider': [compositeConfigurationServiceOverrider]
2025-01-31T08:41:49.341+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.support.DisposableBeanAdapter    : Invoking close() on bean with name 'kubernetesClient'
2025-01-31T08:41:49.341+01:00 TRACE 37050 --- [ionShutdownHook] o.s.b.f.s.DefaultListableBeanFactory     : Retrieved dependent beans for bean 'org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory': [org.springframework.context.annotation.internalConfigurationAnnotationProcessor]

@csviri
Copy link
Contributor

csviri commented Jan 31, 2025

Was able to reproduce with the sample in the starter, it happens also when I downgrade JOSDK version. So something with Spring Boot. Will dig deeper.

@csviri
Copy link
Contributor

csviri commented Jan 31, 2025

So when working with the sample this helped:
https://stackoverflow.com/questions/22380119/why-does-my-spring-boot-app-always-shutdown-immediately-after-starting

    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
    </dependency>

I tried on you example, and interestingly when added to gradle:
implementation("org.springframework.boot:spring-boot-starter-web")
It did not help. Maybe you can play with that @heruan .

My bet is that is that the actual problem is that if not a web application spring just kills it after 1 minute!? Not instantly since we have non-daemon threads running. (But needs to be verified)

IMO, we should do either a blocking command line app this way:
https://stackoverflow.com/a/38949097/737591

But rather, have it always a web app, and also having proper liveness probes exposed through servlets as in Quarkus Operator SDK.

@csviri
Copy link
Contributor

csviri commented Jan 31, 2025

see also: #204

@heruan
Copy link
Author

heruan commented Feb 1, 2025

Thanks for the investigation!

I would say the operator starter should not require the web starter for the application to run. How does the web starter avoid shutdown?

I suppose the web server thread keeps listening to requests as the operator keeps listening to events 🤔

@csviri
Copy link
Contributor

csviri commented Feb 3, 2025

How does the web starter avoid shutdown?

Good questions, actually this might be that we had non-deamon Threads before (this might changed in fabric8 client), or just Spring handles this somehow explicitly (hope not).

I would say the operator starter should not require the web starter

Note that we need that anyways to properly hand health probes.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants