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

De-registering:nacos注册的springcloud微服务偶发执行shutdownHook,服务自动down掉 #4427

Closed
wggy opened this issue Dec 8, 2020 · 17 comments
Labels
status/invalid This doesn't seem right

Comments

@wggy
Copy link

wggy commented Dec 8, 2020

Describe the bug
A clear and concise description of what the bug is.

程序异常退出,启动一台服务,偶发shutdown springcloud服务挂掉,启动三台服务,同样偶发springcloud服务挂掉,且是同时挂掉!!!

下面是日志shutdownHook日志:

Expected behavior
2020-12-08 10:51:13.901 INFO 9163 --- [extShutdownHook] o.s.s.c.ThreadPoolTaskScheduler : Shutting down ExecutorService 'Nacos-Watch-Task-Scheduler'
2020-12-08 10:51:13.913 INFO 9163 --- [extShutdownHook] c.a.c.n.registry.NacosServiceRegistry : De-registering from Nacos Server now...
2020-12-08 10:51:13.916 INFO 9163 --- [extShutdownHook] c.a.c.n.registry.NacosServiceRegistry : De-registration finished.
2020-12-08 10:51:24.266 WARN 9163 --- [extShutdownHook] o.s.b.f.support.DisposableBeanAdapter : Destroy method 'close' on bean with name 'nacosServiceRegistry' threw an exception: java.lang.NullPointerException
2020-12-08 10:51:24.281 INFO 9163 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'applicationTaskExecutor'
2020-12-08 10:51:24.462 INFO 9163 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'browserPersistenceUnit'
2020-12-08 10:51:24.469 INFO 9163 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : Browser-HikariPool - Shutdown initiated...
2020-12-08 10:51:24.473 INFO 9163 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : Browser-HikariPool - Shutdown completed.
2020-12-08 10:51:24.473 INFO 9163 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'sopPersistenceUnit'
2020-12-08 10:51:24.474 INFO 9163 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : SOP-HikariPool - Shutdown initiated...
2020-12-08 10:51:24.486 INFO 9163 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : SOP-HikariPool - Shutdown completed.

Acutally behavior

How to Reproduce
Steps to reproduce the behavior:

  1. Go to '...'
  2. Click on '....'
  3. Scroll down to '....'
  4. See error

Desktop (please complete the following information):

  • OS: [e.g. Centos]
  • Version [e.g. nacos-server 1.3.1, nacos-client 1.3.1]
  • Module [e.g. naming/config]
  • SDK [e.g. original, spring-cloud-alibaba-nacos, dubbo]

Additional context
Add any other context about the problem here.

@wggy
Copy link
Author

wggy commented Dec 8, 2020

补一张shutdown后的日志图片:
image

@chuntaojun
Copy link
Collaborator

是不是自己程序的bug引起的,建议将日志信息打印的更为详细一点看下

@chuntaojun chuntaojun added kind/question Category issues related to questions or problems status/more-info-needed labels Dec 8, 2020
@KomachiSion
Copy link
Collaborator

KomachiSion commented Dec 9, 2020

触发shutdownhook肯定是收到了程序停止的信号,或者哪里主动调用了nacos的shutdown方法,你需要自己排查下。

而且从日志看,不仅是nacos shutdown了,连接池也shutdown了(nacos没有连接池引用)。所以肯定是你程序自己的问题,触发了shutdownhook。

@KomachiSion KomachiSion added status/invalid This doesn't seem right and removed kind/question Category issues related to questions or problems status/more-info-needed labels Dec 9, 2020
@wggy
Copy link
Author

wggy commented Dec 10, 2020

2020-12-10 07:59:55.887 DEBUG 8525 --- [nio-8091-exec-4] org.hibernate.loader.Loader : Result set row: 0
2020-12-10 07:59:55.887 DEBUG 8525 --- [nio-8091-exec-4] org.hibernate.loader.Loader : Result row: EntityKey[com.gitee.sop.openapi.browser.entity.UsersEntity#15869307353321]
2020-12-10 07:59:55.888 DEBUG 8525 --- [nio-8091-exec-4] o.s.orm.jpa.JpaTransactionManager : Initiating transaction commit
2020-12-10 07:59:55.888 DEBUG 8525 --- [nio-8091-exec-4] o.s.orm.jpa.JpaTransactionManager : Committing JPA transaction on EntityManager [SessionImpl(473046285)]
2020-12-10 07:59:55.888 DEBUG 8525 --- [nio-8091-exec-4] o.h.e.t.internal.TransactionImpl : committing
2020-12-10 07:59:55.891 DEBUG 8525 --- [nio-8091-exec-4] o.s.jdbc.datasource.DataSourceUtils : Resetting read-only flag of JDBC Connection [HikariProxyConnection@416495301 wrapping com.mysql.cj.jdbc.ConnectionImpl@30370bb1]
2020-12-10 07:59:55.892 DEBUG 8525 --- [nio-8091-exec-4] o.s.orm.jpa.JpaTransactionManager : Not closing pre-bound JPA EntityManager after transaction
2020-12-10 07:59:55.893 DEBUG 8525 --- [nio-8091-exec-4] m.m.a.RequestResponseBodyMethodProcessor : Using 'application/json', given [application/json, text/plain, /] and supported [application/json, application/+json, application/json, application/+json, application/cbor]
2020-12-10 07:59:55.893 INFO 8525 --- [nio-8091-exec-4] c.g.sop.servercommon.util.AesApiUtil : key: 1ZqI7pWriFbQVma8, iv: qI7pWriFbQVma8RO
2020-12-10 07:59:55.893 INFO 8525 --- [nio-8091-exec-4] c.g.s.o.config.EncryptResponseAdvice : OriginResponseJson: [{"installed":false,"userId":15869307353321,"username":"中文En11"}]
2020-12-10 07:59:55.893 INFO 8525 --- [nio-8091-exec-4] c.g.s.o.config.EncryptResponseAdvice : oauthToken:41ZqI7pWriFbQVma8ROo, EncodedData: +igTKQI8H2YAHwuyzmcz3X7IC67JMaYaPVDm/JUBw/05P5OV4NTa4b0wh5nEOGcpo+LCtCj2yAz2up3fXUaC6h7cwq2e773WATaXiNPcDkM=
2020-12-10 07:59:55.893 DEBUG 8525 --- [nio-8091-exec-4] m.m.a.RequestResponseBodyMethodProcessor : Writing [{data=+igTKQI8H2YAHwuyzmcz3X7IC67JMaYaPVDm/JUBw/05P5OV4NTa4b0wh5nEOGcpo+LCtCj2yAz2up3fXUaC6h7cwq2e77 (truncated)...]
2020-12-10 07:59:55.895 DEBUG 8525 --- [nio-8091-exec-4] o.j.s.OpenEntityManagerInViewInterceptor : Closing JPA EntityManager in OpenEntityManagerInViewInterceptor
2020-12-10 07:59:55.895 DEBUG 8525 --- [nio-8091-exec-4] o.s.web.servlet.DispatcherServlet : Completed 200 OK
2020-12-10 07:59:55.895 DEBUG 8525 --- [nio-8091-exec-4] o.a.coyote.http11.Http11InputBuffer : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2020-12-10 07:59:55.895 DEBUG 8525 --- [nio-8091-exec-4] o.a.tomcat.util.net.SocketWrapperBase : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@3d4fcee:org.apache.tomcat.util.net.NioChannel@5ea996c9:java.nio.channels.SocketChannel[connected local=/172.32.33.81:8091 remote=/172.32.33.81:34006]], Read from buffer: [0]
2020-12-10 07:59:55.896 DEBUG 8525 --- [nio-8091-exec-4] org.apache.tomcat.util.net.NioEndpoint : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@3d4fcee:org.apache.tomcat.util.net.NioChannel@5ea996c9:java.nio.channels.SocketChannel[connected local=/172.32.33.81:8091 remote=/172.32.33.81:34006]], Read direct from socket: [0]
2020-12-10 07:59:55.896 DEBUG 8525 --- [nio-8091-exec-4] o.a.coyote.http11.Http11InputBuffer : Received []
2020-12-10 07:59:55.896 DEBUG 8525 --- [nio-8091-exec-4] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@3d4fcee:org.apache.tomcat.util.net.NioChannel@5ea996c9:java.nio.channels.SocketChannel[connected local=/172.32.33.81:8091 remote=/172.32.33.81:34006]], Status in: [OPEN_READ], State out: [OPEN]
2020-12-10 07:59:55.896 DEBUG 8525 --- [nio-8091-exec-4] org.apache.tomcat.util.net.NioEndpoint : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@3d4fcee:org.apache.tomcat.util.net.NioChannel@5ea996c9:java.nio.channels.SocketChannel[connected local=/172.32.33.81:8091 remote=/172.32.33.81:34006]]
2020-12-10 07:59:57.232 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@6e496b3a11 pairs: {PUT /nacos/v1/ns/instance/beat?app=unknown&serviceName=DEFAULT_GROUP%40%40sop-openapi&namespaceId=public&port=8091&clusterName=DEFAULT&ip=172.32.33.81 HTTP/1.1: null}{Content-Type: application/x-www-form-urlencoded;charset=UTF-8}{Accept-Charset: UTF-8}{Accept-Encoding: gzip,deflate,sdch}{Client-Version: 1.3.3}{User-Agent: Nacos-Java-Client:v1.3.3}{RequestId: 65af9b60-4e2d-45e4-98e1-07c3308269c0}{Request-Module: Naming}{Host: 52.81.162.154:8084}{Accept: text/html, image/gif, image/jpeg, *; q=.2, /; q=.2}{Connection: keep-alive}
2020-12-10 07:59:57.233 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@2af12a276 pairs: {null: HTTP/1.1 200}{Content-Type: application/json;charset=UTF-8}{Transfer-Encoding: chunked}{Date: Thu, 10 Dec 2020 07:59:57 GMT}{Keep-Alive: timeout=60}{Connection: keep-alive}
2020-12-10 07:59:58.860 DEBUG 8525 --- [ool housekeeper] com.zaxxer.hikari.pool.HikariPool : Browser-HikariPool - Before cleanup stats (total=1, active=0, idle=1, waiting=0)
2020-12-10 07:59:58.860 DEBUG 8525 --- [ool housekeeper] com.zaxxer.hikari.pool.HikariPool : Browser-HikariPool - After cleanup stats (total=1, active=0, idle=1, waiting=0)
2020-12-10 07:59:58.860 DEBUG 8525 --- [ool housekeeper] com.zaxxer.hikari.pool.HikariPool : Browser-HikariPool - Fill pool skipped, pool is at sufficient level.
2020-12-10 08:00:02.234 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@22c9003411 pairs: {PUT /nacos/v1/ns/instance/beat?app=unknown&serviceName=DEFAULT_GROUP%40%40sop-openapi&namespaceId=public&port=8091&clusterName=DEFAULT&ip=172.32.33.81 HTTP/1.1: null}{Content-Type: application/x-www-form-urlencoded;charset=UTF-8}{Accept-Charset: UTF-8}{Accept-Encoding: gzip,deflate,sdch}{Client-Version: 1.3.3}{User-Agent: Nacos-Java-Client:v1.3.3}{RequestId: 1bf81de5-f9af-44a6-9783-77bace82bdf5}{Request-Module: Naming}{Host: 52.81.162.154:8084}{Accept: text/html, image/gif, image/jpeg, *; q=.2, /; q=.2}{Connection: keep-alive}
2020-12-10 08:00:02.236 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@2121a8916 pairs: {null: HTTP/1.1 200}{Content-Type: application/json;charset=UTF-8}{Transfer-Encoding: chunked}{Date: Thu, 10 Dec 2020 08:00:02 GMT}{Keep-Alive: timeout=60}{Connection: keep-alive}
2020-12-10 08:00:02.728 DEBUG 8525 --- [.naming.updater] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@452dd99611 pairs: {GET /nacos/v1/ns/instance/list?app=unknown&healthyOnly=false&namespaceId=public&clientIP=172.32.33.81&serviceName=DEFAULT_GROUP%40%40sop-openapi&udpPort=43394&clusters=DEFAULT HTTP/1.1: null}{Content-Type: application/x-www-form-urlencoded;charset=UTF-8}{Accept-Charset: UTF-8}{Accept-Encoding: gzip,deflate,sdch}{Client-Version: 1.3.3}{User-Agent: Nacos-Java-Client:v1.3.3}{RequestId: 6010f8b5-f3fd-4558-99fd-e1f30e34951e}{Request-Module: Naming}{Host: 52.81.162.154:8084}{Accept: text/html, image/gif, image/jpeg, *; q=.2, /; q=.2}{Connection: keep-alive}
2020-12-10 08:00:02.730 DEBUG 8525 --- [.naming.updater] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@555dc8706 pairs: {null: HTTP/1.1 200}{Content-Type: application/json;charset=UTF-8}{Transfer-Encoding: chunked}{Date: Thu, 10 Dec 2020 08:00:02 GMT}{Keep-Alive: timeout=60}{Connection: keep-alive}
2020-12-10 08:00:07.237 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@414173411 pairs: {PUT /nacos/v1/ns/instance/beat?app=unknown&serviceName=DEFAULT_GROUP%40%40sop-openapi&namespaceId=public&port=8091&clusterName=DEFAULT&ip=172.32.33.81 HTTP/1.1: null}{Content-Type: application/x-www-form-urlencoded;charset=UTF-8}{Accept-Charset: UTF-8}{Accept-Encoding: gzip,deflate,sdch}{Client-Version: 1.3.3}{User-Agent: Nacos-Java-Client:v1.3.3}{RequestId: a118e5de-608c-43c2-aff0-a912af7c07e8}{Request-Module: Naming}{Host: 52.81.162.154:8084}{Accept: text/html, image/gif, image/jpeg, *; q=.2, /; q=.2}{Connection: keep-alive}
2020-12-10 08:00:07.238 DEBUG 8525 --- [ing.beat.sender] s.n.www.protocol.http.HttpURLConnection : sun.net.www.MessageHeader@2797b5836 pairs: {null: HTTP/1.1 200}{Content-Type: application/json;charset=UTF-8}{Transfer-Encoding: chunked}{Date: Thu, 10 Dec 2020 08:00:07 GMT}{Keep-Alive: timeout=60}{Connection: keep-alive}
2020-12-10 08:00:07.312 DEBUG 8525 --- [extShutdownHook] ConfigServletWebServerApplicationContext : Closing org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@3e57cd70, started on Thu Dec 10 07:26:14 UTC 2020, parent: org.springframework.context.annotation.AnnotationConfigApplicationContext@61a485d2
2020-12-10 08:00:07.331 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Stopping beans in phase 2147483647
2020-12-10 08:00:07.333 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Bean 'documentationPluginsBootstrapper' completed its stop procedure
2020-12-10 08:00:07.335 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Bean 'webServerGracefulShutdown' completed its stop procedure
2020-12-10 08:00:07.335 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Stopping beans in phase 2147483646
2020-12-10 08:00:07.391 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Bean 'webServerStartStop' completed its stop procedure
2020-12-10 08:00:07.391 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Stopping beans in phase 0
2020-12-10 08:00:07.393 INFO 8525 --- [extShutdownHook] o.s.s.c.ThreadPoolTaskScheduler : Shutting down ExecutorService 'Nacos-Watch-Task-Scheduler'
2020-12-10 08:00:07.396 DEBUG 8525 --- [extShutdownHook] o.s.c.support.DefaultLifecycleProcessor : Bean 'nacosWatch' completed its stop procedure
2020-12-10 08:00:07.398 DEBUG 8525 --- [extShutdownHook] o.s.d.r.l.RedisMessageListenerContainer : Stopped RedisMessageListenerContainer
2020-12-10 08:00:07.411 INFO 8525 --- [extShutdownHook] c.a.c.n.registry.NacosServiceRegistry : De-registering from Nacos Server now...
2020-12-10 08:00:07.431 INFO 8525 --- [extShutdownHook] c.a.c.n.registry.NacosServiceRegistry : De-registration finished.
2020-12-10 08:00:16.380 DEBUG 8525 --- [ngPollService-1] c.c.f.a.i.RemoteConfigLongPollService : Long polling response: 304, url: http://172.32.33.81:8080/notifications/v2?cluster=default&appId=sop-openapi&ip=172.32.33.81&notifications=%5B%7B%22namespaceName%22%3A%22application%22%2C%22notificationId%22%3A50%7D%2C%7B%22namespaceName%22%3A%22sorts%22%2C%22notificationId%22%3A35%7D%2C%7B%22namespaceName%22%3A%22redis%22%2C%22notificationId%22%3A44%7D%5D
2020-12-10 08:00:16.381 DEBUG 8525 --- [ngPollService-1] c.c.f.a.i.RemoteConfigLongPollService : Long polling from http://172.32.33.81:8080/notifications/v2?cluster=default&appId=sop-openapi&ip=172.32.33.81&notifications=%5B%7B%22namespaceName%22%3A%22application%22%2C%22notificationId%22%3A50%7D%2C%7B%22namespaceName%22%3A%22sorts%22%2C%22notificationId%22%3A35%7D%2C%7B%22namespaceName%22%3A%22redis%22%2C%22notificationId%22%3A44%7D%5D
2020-12-10 08:00:17.737 WARN 8525 --- [extShutdownHook] o.s.b.f.support.DisposableBeanAdapter : Destroy method 'close' on bean with name 'nacosServiceRegistry' threw an exception

java.lang.NullPointerException: null
at com.alibaba.cloud.nacos.NacosServiceManager.nacosServiceShutDown(NacosServiceManager.java:115) ~[spring-cloud-starter-alibaba-nacos-discovery-2.2.3.RELEASE.jar!/:2.2.3.RELEASE]
at com.alibaba.cloud.nacos.registry.NacosServiceRegistry.close(NacosServiceRegistry.java:112) ~[spring-cloud-starter-alibaba-nacos-discovery-2.2.3.RELEASE.jar!/:2.2.3.RELEASE]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_161]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_161]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_161]
at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_161]
at org.springframework.beans.factory.support.DisposableBeanAdapter.invokeCustomDestroyMethod(DisposableBeanAdapter.java:339) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DisposableBeanAdapter.destroy(DisposableBeanAdapter.java:273) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroyBean(DefaultSingletonBeanRegistry.java:587) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingleton(DefaultSingletonBeanRegistry.java:559) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingleton(DefaultListableBeanFactory.java:1092) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.destroySingletons(DefaultSingletonBeanRegistry.java:520) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.beans.factory.support.DefaultListableBeanFactory.destroySingletons(DefaultListableBeanFactory.java:1085) [spring-beans-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.destroyBeans(AbstractApplicationContext.java:1061) [spring-context-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.context.support.AbstractApplicationContext.doClose(AbstractApplicationContext.java:1030) [spring-context-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]
at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.doClose(ServletWebServerApplicationContext.java:170) [spring-boot-2.3.4.RELEASE.jar!/:2.3.4.RELEASE]
at org.springframework.context.support.AbstractApplicationContext$1.run(AbstractApplicationContext.java:949) [spring-context-5.2.9.RELEASE.jar!/:5.2.9.RELEASE]

2020-12-10 08:00:17.816 INFO 8525 --- [extShutdownHook] o.s.s.concurrent.ThreadPoolTaskExecutor : Shutting down ExecutorService 'applicationTaskExecutor'
2020-12-10 08:00:17.821 DEBUG 8525 --- [extShutdownHook] io.lettuce.core.RedisChannelHandler : closeAsync()
2020-12-10 08:00:17.821 DEBUG 8525 --- [extShutdownHook] i.lettuce.core.protocol.DefaultEndpoint : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, epid=0x1] closeAsync()
2020-12-10 08:00:17.827 DEBUG 8525 --- [ioEventLoop-4-1] io.lettuce.core.protocol.CommandHandler : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, chid=0x1] channelInactive()
2020-12-10 08:00:17.828 DEBUG 8525 --- [extShutdownHook] io.lettuce.core.RedisClient : Initiate shutdown (100, 100, MILLISECONDS)
2020-12-10 08:00:17.829 DEBUG 8525 --- [ioEventLoop-4-1] i.lettuce.core.protocol.DefaultEndpoint : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, epid=0x1] deactivating endpoint handler
2020-12-10 08:00:17.829 DEBUG 8525 --- [ioEventLoop-4-1] io.lettuce.core.protocol.CommandHandler : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, chid=0x1] channelInactive() done
2020-12-10 08:00:17.830 DEBUG 8525 --- [ioEventLoop-4-1] i.l.core.protocol.ConnectionWatchdog : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, last known addr=superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379] channelInactive()
2020-12-10 08:00:17.830 DEBUG 8525 --- [ioEventLoop-4-1] i.l.core.protocol.ConnectionWatchdog : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, last known addr=superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379] Reconnect scheduling disabled
2020-12-10 08:00:17.831 DEBUG 8525 --- [ioEventLoop-4-1] io.lettuce.core.protocol.CommandHandler : [channel=0xd114962e, /172.32.33.81:35246 -> superbrowser-test.tvlcc1.ng.0001.cnn1.cache.amazonaws.com.cn/172.32.15.90:6379, chid=0x1] channelUnregistered()
2020-12-10 08:00:17.844 DEBUG 8525 --- [extShutdownHook] i.l.c.r.DefaultEventLoopGroupProvider : Release executor io.netty.channel.nio.NioEventLoopGroup@7774e262
2020-12-10 08:00:17.946 DEBUG 8525 --- [ioEventLoop-4-1] io.netty.buffer.PoolThreadCache : Freed 8 thread-local buffer(s) from thread: lettuce-nioEventLoop-4-1
2020-12-10 08:00:17.951 DEBUG 8525 --- [extShutdownHook] i.l.c.resource.DefaultClientResources : Initiate shutdown (0, 2, SECONDS)
2020-12-10 08:00:17.954 DEBUG 8525 --- [extShutdownHook] i.l.c.r.DefaultEventLoopGroupProvider : Initiate shutdown (0, 2, SECONDS)
2020-12-10 08:00:17.960 INFO 8525 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'browserPersistenceUnit'
2020-12-10 08:00:17.960 DEBUG 8525 --- [extShutdownHook] o.hibernate.internal.SessionFactoryImpl : HHH000031: Closing
2020-12-10 08:00:17.960 DEBUG 8525 --- [extShutdownHook] o.h.type.spi.TypeConfiguration$Scope : Un-scoping TypeConfiguration [org.hibernate.type.spi.TypeConfiguration$Scope@1bca4ab3] from SessionFactory [org.hibernate.internal.SessionFactoryImpl@1e008f36]
2020-12-10 08:00:17.960 DEBUG 8525 --- [extShutdownHook] o.h.s.i.AbstractServiceRegistryImpl : Implicitly destroying ServiceRegistry on de-registration of all child ServiceRegistries
2020-12-10 08:00:17.962 DEBUG 8525 --- [extShutdownHook] o.h.b.r.i.BootstrapServiceRegistryImpl : Implicitly destroying Boot-strap registry on de-registration of all child ServiceRegistries
2020-12-10 08:00:17.962 INFO 8525 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : Browser-HikariPool - Shutdown initiated...
2020-12-10 08:00:17.962 DEBUG 8525 --- [extShutdownHook] com.zaxxer.hikari.pool.HikariPool : Browser-HikariPool - Before shutdown stats (total=1, active=0, idle=1, waiting=0)
2020-12-10 08:00:17.964 DEBUG 8525 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : Browser-HikariPool - Closing connection com.mysql.cj.jdbc.ConnectionImpl@30370bb1: (connection evicted)
2020-12-10 08:00:17.964 DEBUG 8525 --- [extShutdownHook] com.zaxxer.hikari.pool.HikariPool : Browser-HikariPool - After shutdown stats (total=0, active=0, idle=0, waiting=0)
2020-12-10 08:00:17.965 INFO 8525 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : Browser-HikariPool - Shutdown completed.
2020-12-10 08:00:17.965 INFO 8525 --- [extShutdownHook] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'sopPersistenceUnit'
2020-12-10 08:00:17.965 DEBUG 8525 --- [extShutdownHook] o.hibernate.internal.SessionFactoryImpl : HHH000031: Closing
2020-12-10 08:00:17.965 DEBUG 8525 --- [extShutdownHook] o.h.type.spi.TypeConfiguration$Scope : Un-scoping TypeConfiguration [org.hibernate.type.spi.TypeConfiguration$Scope@1361a50e] from SessionFactory [org.hibernate.internal.SessionFactoryImpl@36ac8a63]
2020-12-10 08:00:17.965 DEBUG 8525 --- [extShutdownHook] o.h.s.i.AbstractServiceRegistryImpl : Implicitly destroying ServiceRegistry on de-registration of all child ServiceRegistries
2020-12-10 08:00:17.966 DEBUG 8525 --- [extShutdownHook] o.h.b.r.i.BootstrapServiceRegistryImpl : Implicitly destroying Boot-strap registry on de-registration of all child ServiceRegistries
2020-12-10 08:00:17.966 INFO 8525 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : SOP-HikariPool - Shutdown initiated...
2020-12-10 08:00:17.966 DEBUG 8525 --- [extShutdownHook] com.zaxxer.hikari.pool.HikariPool : SOP-HikariPool - Before shutdown stats (total=1, active=0, idle=1, waiting=0)
2020-12-10 08:00:17.966 DEBUG 8525 --- [nnection closer] com.zaxxer.hikari.pool.PoolBase : SOP-HikariPool - Closing connection com.mysql.cj.jdbc.ConnectionImpl@3f34c2af: (connection evicted)
2020-12-10 08:00:17.967 DEBUG 8525 --- [extShutdownHook] com.zaxxer.hikari.pool.HikariPool : SOP-HikariPool - After shutdown stats (total=0, active=0, idle=0, waiting=0)
2020-12-10 08:00:17.971 INFO 8525 --- [extShutdownHook] com.zaxxer.hikari.HikariDataSource : SOP-HikariPool - Shutdown completed.

@wggy
Copy link
Author

wggy commented Dec 10, 2020

确实是触发了shutdownHook,服务部署在aws云主机,nacos使用的是外网地址,不知道是否是心跳断开引起的shutdownHook

@KomachiSion
Copy link
Collaborator

nacos 本身不会触发,如果你发现是NacosServiceRegistry触发的,请提issue到SCA社区,不过我建议你排查一下自己的逻辑,大概率是你自己的逻辑触发了shutdown或者是aws帮你kill了。

@dengxixian008
Copy link

使用kill -15,在程序里addShutdownHook添加钩子后,在进入这个方法的时候就会去触发Naocos注销实例,其实我在这个方法中又等待30秒的,这个情况要如何处理啊?

@Learnthe
Copy link

我也碰到了这个问题 服务经常被shutdown,后面这个情况是怎么解决的?

@XiaoZhiSnow
Copy link

XiaoZhiSnow commented Aug 6, 2021

我也遇到了这个问题,这是我个人在csdn上的分析, 感觉就是nacos的bug,https://blog.csdn.net/ycuzrz112280/article/details/119453697

@liangsqrt
Copy link

我也碰到了,正在学springb-cloud-alibaba, 照着视频来的,也是过一会就自动挂掉

@devswork
Copy link

我也碰到了,微服务中只有一些业务API,然后就遭遇了宕机......
https://z3.ax1x.com/2021/10/22/56L1ld.png

@baisexiaohei
Copy link

同问

@luguoqi
Copy link

luguoqi commented Mar 21, 2022

解决了么,怎么解决的啊

@weideng365
Copy link

解决了么,怎么解决的啊

可以把你的java启动命令截图出来。我看下

@hellevil009
Copy link

我遇到的问题更奇怪,手动调用启动脚本服务能开住,不会掉,用Jenkins自动化走同样的脚本启动,服务就会先起来再挂掉

@yc20180222
Copy link

同问

@jrd77
Copy link

jrd77 commented Apr 21, 2023

当我们把项目部署到服务器上时,只有一直保持linux终端的连接才能够运行项目,当我们把连接软件Xshell或者Finalshell连接工具关掉时,项目也就停止运行。只要用了nohup命令,我们的项目就能够一直运行了,此时就实现了我们需求。

大概是因为这个原因
解决方式:
1.脚本启动
2.nohup启动

参考: https://blog.csdn.net/qq_45830276/article/details/126044645

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
status/invalid This doesn't seem right
Projects
None yet
Development

No branches or pull requests