通过/actuator/restart重启ApplicationContext后,执行器无法自动注册

hashmaparraylist commented 2 years ago

Please answer some questions before submitting your issue. Thanks!

Which version of XXL-JOB do you using?

spring boot 2.5.1 spring cloud 2020.0.3 xxl-job-core 2.3.0

spring cloud 主要使用下列组件

spring-cloud-starter-kubernetes-fabric8-config

Expected behavior

执行器(基于Spring Boot)部署在K8S环境中，使用K8S的ConfigMap作为配置中心。当执行器对应的ConfigMap内容发生变化后会想执行器的 /actuator/restart 发送一个POST请求重启整个Spring容器。 (上述行为是通过spring-cloud-starter-kubernetes-fabric8-config实现的。)

此时执行器并没有和正常启动时一样注册到调度中心。

Actual behavior

执行器没有办法自动注册到调度中心

Steps to reproduce the behavior

在springboot的配置文件中加入下面的配置打开actuator的restart接口

# actuator 配置
management:
  endpoint:
    restart:
      enabled: true
  endpoints:
    web:
      exposure:
        include: health, info, env, restart

等执行器完全启动后通过postman或是curl命令发送post请求

curl --location --request POST 'http://localhost:8080/actuator/restart'

Other information

正常启动时的LOG日志

2022-05-31 16:42:14.345  INFO [demo-job-executor,,] 27420 --- [           main] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:demoJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@5f2ad3d5[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#demoJobHandler]
2022-05-31 16:42:14.345  INFO [demo-job-executor,,] 27420 --- [           main] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:shardingJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@703eead0[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#shardingJobHandler]
2022-05-31 16:42:14.345  INFO [demo-job-executor,,] 27420 --- [           main] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:commandJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@674fd531[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#commandJobHandler]
2022-05-31 16:42:14.345  INFO [demo-job-executor,,] 27420 --- [           main] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:httpJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@7f53b345[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#httpJobHandler]
2022-05-31 16:42:14.345  INFO [demo-job-executor,,] 27420 --- [           main] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:demoJobHandler2, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@76ee7301[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#demoJobHandler2]
2022-05-31 16:42:14.404  INFO [demo-job-executor,,] 27420 --- [      Thread-12] com.xxl.job.core.server.EmbedServer      : >>>>>>>>>>> xxl-job remoting server start success, nettype = class com.xxl.job.core.server.EmbedServer, port = 9999
2022-05-31 16:42:14.427 DEBUG [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job registry success, registryParam:RegistryParam{registryGroup='EXECUTOR', registryKey='demo-dev', registryValue='http://192.168.11.180:9999/'}, registryResult:ReturnT [code=200, msg=null, content=null]

向/actuator/restart 发送POST请求后的重启日志

2022-05-31 16:43:14.324  INFO [demo-job-executor,,] 27420 --- [nio-8080-exec-2] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-05-31 16:43:14.324  INFO [demo-job-executor,,] 27420 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-05-31 16:43:14.325  INFO [demo-job-executor,,] 27420 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet        : Completed initialization in 1 ms
2022-05-31 16:43:14.448 DEBUG [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job registry success, registryParam:RegistryParam{registryGroup='EXECUTOR', registryKey='demo-dev', registryValue='http://192.168.11.180:9999/'}, registryResult:ReturnT [code=200, msg=null, content=null]
2022-05-31 16:43:15.588  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2022-05-31 16:43:15.588  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.a.c.c.C.[Tomcat].[localhost].[/]       : Destroying Spring FrameworkServlet 'dispatcherServlet'
2022-05-31 16:43:15.594  INFO [demo-job-executor,,] 27420 --- [      Thread-12] com.xxl.job.core.server.EmbedServer      : >>>>>>>>>>> xxl-job remoting server stop.
2022-05-31 16:43:15.602  INFO [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job registry-remove success, registryParam:RegistryParam{registryGroup='EXECUTOR', registryKey='demo-dev', registryValue='http://192.168.11.180:9999/'}, registryResult:ReturnT [code=200, msg=null, content=null]
2022-05-31 16:43:15.602  INFO [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job, executor registry thread destory.
2022-05-31 16:43:15.602  INFO [demo-job-executor,,] 27420 --- [      Thread-16] com.xxl.job.core.server.EmbedServer      : >>>>>>>>>>> xxl-job remoting server destroy success.
2022-05-31 16:43:15.602  INFO [demo-job-executor,,] 27420 --- [rCallbackThread] c.x.j.core.thread.TriggerCallbackThread  : >>>>>>>>>>> xxl-job, executor callback thread destory.
2022-05-31 16:43:15.602  INFO [demo-job-executor,,] 27420 --- [      Thread-11] c.x.j.core.thread.TriggerCallbackThread  : >>>>>>>>>>> xxl-job, executor retry callback thread destory.
2022-05-31 16:43:15.674  WARN [demo-job-executor,,] 27420 --- [      Thread-16] ubernetesProfileEnvironmentPostProcessor : Not running inside kubernetes. Skipping 'kubernetes' profile activation.
2022-05-31 16:43:15.697  WARN [demo-job-executor,,] 27420 --- [      Thread-16] o.s.c.k.f.Fabric8AutoConfiguration       : No namespace has been detected. Please specify KUBERNETES_NAMESPACE env var, or use a later kubernetes version (1.3 or later)

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.5.1)

2022-05-31 16:43:15.728  WARN [demo-job-executor,,] 27420 --- [      Thread-16] ubernetesProfileEnvironmentPostProcessor : Not running inside kubernetes. Skipping 'kubernetes' profile activation.
2022-05-31 16:43:15.729  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.s.demo.ms.job.executor.Application  : No active profile set, falling back to default profiles: default
2022-05-31 16:43:15.894  INFO [demo-job-executor,,] 27420 --- [      Thread-16] .s.d.r.c.RepositoryConfigurationDelegate : Multiple Spring Data modules found, entering strict repository configuration mode!
2022-05-31 16:43:15.894  INFO [demo-job-executor,,] 27420 --- [      Thread-16] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data Redis repositories in DEFAULT mode.
2022-05-31 16:43:15.897  INFO [demo-job-executor,,] 27420 --- [      Thread-16] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 3 ms. Found 0 Redis repository interfaces.
2022-05-31 16:43:15.928  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.s.cloud.context.scope.GenericScope     : BeanFactory id=36b2b3e6-025c-3c75-b534-abaff202c9f4
2022-05-31 16:43:16.001  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-05-31 16:43:16.002  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-05-31 16:43:16.002  INFO [demo-job-executor,,] 27420 --- [      Thread-16] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2022-05-31 16:43:16.007  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-05-31 16:43:16.007  INFO [demo-job-executor,,] 27420 --- [      Thread-16] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 277 ms
2022-05-31 16:43:24.731  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.s.b.a.e.web.EndpointLinksResolver      : Exposing 6 endpoint(s) beneath base path '/actuator'
2022-05-31 16:43:26.029  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:demoJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@33b7d7c6[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#demoJobHandler]
2022-05-31 16:43:26.029  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:shardingJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@6409597a[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#shardingJobHandler]
2022-05-31 16:43:26.029  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:commandJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@3802d53d[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#commandJobHandler]
2022-05-31 16:43:26.029  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:httpJobHandler, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@29538b6[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#httpJobHandler]
2022-05-31 16:43:26.029  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.xxl.job.core.executor.XxlJobExecutor   : >>>>>>>>>>> xxl-job register jobhandler success, name:demoJobHandler2, jobHandler:com.xxl.job.core.handler.impl.MethodJobHandler@f11c6c5[class cn.sh.demo.ms.job.executor.sample.job.SampleXxlJob#demoJobHandler2]
2022-05-31 16:43:26.043  INFO [demo-job-executor,,] 27420 --- [rCallbackThread] c.x.j.core.thread.TriggerCallbackThread  : >>>>>>>>>>> xxl-job, executor callback thread destory.
2022-05-31 16:43:26.044  INFO [demo-job-executor,,] 27420 --- [      Thread-24] c.x.j.core.thread.TriggerCallbackThread  : >>>>>>>>>>> xxl-job, executor retry callback thread destory.
2022-05-31 16:43:26.046  INFO [demo-job-executor,,] 27420 --- [      Thread-25] com.xxl.job.core.server.EmbedServer      : >>>>>>>>>>> xxl-job remoting server start success, nettype = class com.xxl.job.core.server.EmbedServer, port = 9999
2022-05-31 16:43:26.049  INFO [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job registry-remove success, registryParam:RegistryParam{registryGroup='EXECUTOR', registryKey='demo-dev', registryValue='http://192.168.11.180:9999/'}, registryResult:ReturnT [code=200, msg=null, content=null]
2022-05-31 16:43:26.050  INFO [demo-job-executor,,] 27420 --- [rRegistryThread] c.x.j.c.thread.ExecutorRegistryThread    : >>>>>>>>>>> xxl-job, executor registry thread destory.
2022-05-31 16:43:26.339  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-05-31 16:43:26.350  INFO [demo-job-executor,,] 27420 --- [      Thread-16] c.s.demo.ms.job.executor.Application  : Started Application in 10.716 seconds (JVM running for 78.887)
2022-05-31 16:43:26.352  INFO [demo-job-executor,,] 27420 --- [      Thread-16] o.s.c.context.restart.RestartEndpoint    : Restarted

hashmaparraylist commented 2 years ago

感觉应该是ExecutorRegistryThread这个类的问题

ExecutorRegistryThread被作为一个单例来使用的。无论是start()还是stop()方法都是通过下面这个标志位变量来处理的。

private volatile boolean toStop = false;

当/actuator/restart被触发的时候，应该只是触发了ApplicationContext的restart，这个时候会执行器会先调用ExecutorRegistryThread的stop()再调用start()，

在stop方法里

    public void toStop() {
        toStop = true;

        // interrupt and wait
        if (registryThread != null) {
            registryThread.interrupt();
            try {
                registryThread.join();
            } catch (InterruptedException e) {
                logger.error(e.getMessage(), e);
            }
        }

    }

toStop这个标志位被标记成true了，所以在start里就没有办法完成执行器的注册了。归根结底/actuator/restart这个并不会触发整个jvm的重启，所以作为单例的ExecutorRegistryThread 的成员变量不会被重置。

感觉在使用Nacos作为配置中心可能也会有相同的问题。

hashmaparraylist commented 1 year ago

以下几个单例模式的线程都有这个问题。

ExecutorRegistryThread
JobLogFileCleanThread
TriggerCallbackThread

xuxueli / xxl-job