[ https://issues.apache.org/jira/browse/NIFI-11841?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17745405#comment-17745405 ]
Dheeraj Joshi commented on NIFI-11841: -------------------------------------- When bootstrap prints {{Shutdown in progress}} unable to take any thread dumps {code:java} Exception in thread "main" java.net.ConnectException: Connection refused at java.base/sun.nio.ch.Net.connect0(Native Method) at java.base/sun.nio.ch.Net.connect(Net.java:579) at java.base/sun.nio.ch.Net.connect(Net.java:568) at java.base/sun.nio.ch.NioSocketImpl.connect(NioSocketImpl.java:588) at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:327) at java.base/java.net.Socket.connect(Socket.java:633) at java.base/java.net.Socket.connect(Socket.java:583) at org.apache.nifi.bootstrap.RunNiFi.sendRequest(RunNiFi.java:853) at org.apache.nifi.bootstrap.RunNiFi.makeRequest(RunNiFi.java:827) at org.apache.nifi.bootstrap.RunNiFi.dump(RunNiFi.java:782) at org.apache.nifi.bootstrap.RunNiFi.main(RunNiFi.java:320) {code} > Nifi in cluster setup doesn't stop within the graceful shutdown period > ---------------------------------------------------------------------- > > Key: NIFI-11841 > URL: https://issues.apache.org/jira/browse/NIFI-11841 > Project: Apache NiFi > Issue Type: Bug > Components: Core Framework > Affects Versions: 1.22.0 > Reporter: Dheeraj Joshi > Priority: Major > Attachments: bootstrap.conf, nifi-app.log, nifi-bootstrap.log, > nifi.properties, zookeeper.properties > > > Bootstrap logs show the following logs when one of the nodes in a 3-node > cluster is stopped > {code:java} > 2023-07-20 11:10:49,847 INFO [main] org.apache.nifi.bootstrap.Command > Launched Apache NiFi with Process ID 18579 > 2023-07-20 11:10:50,475 INFO [NiFi Bootstrap Command Listener] > org.apache.nifi.bootstrap.RunNiFi Apache NiFi now running and listening for > Bootstrap requests on port 64739 > 2023-07-20 11:12:15,723 INFO [main] o.a.n.b.NotificationServiceManager > Successfully loaded the following 0 services: [] > 2023-07-20 11:12:15,725 INFO [main] org.apache.nifi.bootstrap.RunNiFi > Registered no Notification Services for Notification Type NIFI_STARTED > 2023-07-20 11:12:15,725 INFO [main] org.apache.nifi.bootstrap.RunNiFi > Registered no Notification Services for Notification Type NIFI_STOPPED > 2023-07-20 11:12:15,725 INFO [main] org.apache.nifi.bootstrap.RunNiFi > Registered no Notification Services for Notification Type NIFI_DIED > 2023-07-20 11:12:15,750 INFO [main] org.apache.nifi.bootstrap.Command Apache > NiFi has accepted the Shutdown Command and is shutting down now > 2023-07-20 11:12:15,859 INFO [main] org.apache.nifi.bootstrap.Command NiFi > PID [18579] shutdown in progress... > 2023-07-20 11:12:17,896 INFO [main] org.apache.nifi.bootstrap.Command NiFi > PID [18579] shutdown in progress... > 2023-07-20 11:12:19,919 INFO [main] org.apache.nifi.bootstrap.Command NiFi > PID [18579] shutdown in progress...{code} > The shutdown in progress message gets repeated till > {code:java} > graceful.shutdown.seconds{code} > is elapsed. > Nifi app logs print socket exception during the shutdown but eventually shuts > down the application server server > {code:java} > 2023-07-20 11:12:15,750 INFO [pool-2-thread-2] > org.apache.nifi.BootstrapListener Received SHUTDOWN request from Bootstrap > 2023-07-20 11:12:15,750 INFO [pool-2-thread-2] org.apache.nifi.NiFi > Application Server shutdown started > 2023-07-20 11:12:15,755 INFO [pool-2-thread-2] > o.eclipse.jetty.server.AbstractConnector Stopped > ServerConnector@2407a36c{HTTP/1.1, (http/1.1)} > {127.0.0.1:8080} > 2023-07-20 11:12:15,756 INFO [pool-2-thread-2] > org.eclipse.jetty.server.session node0 Stopped scavenging > 2023-07-20 11:12:15,769 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@7cfb8e98{nifi-error,/,null,STOPPED} > {./work/nar/extensions/nifi-server-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-error-1.22.0.war} > 2023-07-20 11:12:15,782 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@2aa5bd48{nifi-docs,/nifi-docs,null,STOPPED} > {./work/nar/extensions/nifi-server-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-docs-1.22.0.war} > 2023-07-20 11:12:15,798 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@133aacbe{nifi-content-viewer,/nifi-content-viewer,null,STOPPED} > {./work/nar/extensions/nifi-server-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-content-viewer-1.22.0.war} > 2023-07-20 11:12:15,803 INFO [pool-2-thread-2] > o.a.n.w.c.ApplicationStartupContextListener Flow Service shutdown started > 2023-07-20 11:12:15,803 INFO [pool-2-thread-2] > o.a.n.c.c.node.NodeClusterCoordinator Status of 127.0.0.1:8080 changed from > NodeConnectionStatus[nodeId=127.0.0.1:8080, state=CONNECTED, updateId=50] to > NodeConnectionStatus[nodeId=127.0.0.1:8080, state=DISCONNECTED, Disconnect > Code=Node was Shutdown, Disconnect Reason=Node was Shutdown, updateId=50] > 2023-07-20 11:12:15,809 INFO [pool-2-thread-2] > o.a.n.c.c.node.NodeClusterCoordinator Successfully notified other nodes that > I am shutting down > 2023-07-20 11:12:15,811 INFO [Curator-Framework-0] > o.a.c.f.imps.CuratorFrameworkImpl backgroundOperationsLoop exiting > 2023-07-20 11:12:15,813 INFO [RequestThrottler] > o.a.zookeeper.server.ZooKeeperServer Submitting global closeSession request > for session 0x10001c338080000 > 2023-07-20 11:12:15,815 INFO [Process Cluster Protocol Request-3] > o.a.n.c.c.node.NodeClusterCoordinator Status of 127.0.0.1:8080 changed from > NodeConnectionStatus[nodeId=127.0.0.1:8080, state=DISCONNECTED, Disconnect > Code=Node was Shutdown, Disconnect Reason=Node was Shutdown, updateId=50] to > NodeConnectionStatus[nodeId=127.0.0.1:8080, state=DISCONNECTED, Disconnect > Code=Node was Shutdown, Disconnect Reason=Node was Shutdown, updateId=50] > 2023-07-20 11:12:15,816 INFO [Process Cluster Protocol Request-3] > o.a.n.c.p.impl.SocketProtocolListener Finished processing request > 62a9da74-38d3-4bce-83a6-8f55aa7bec64 (type=NODE_STATUS_CHANGE, length=1184 > bytes) from localhost in 3 millis > 2023-07-20 11:12:15,967 INFO [pool-2-thread-2] > o.a.n.c.l.e.CuratorLeaderElectionManager > CuratorLeaderElectionManager[stopped=true] stopped and closed > 2023-07-20 11:12:15,967 INFO [pool-2-thread-2] > o.a.n.c.c.h.AbstractHeartbeatMonitor Heartbeat Monitor stopped > 2023-07-20 11:12:15,968 INFO [pool-2-thread-2] > o.apache.nifi.controller.FlowController Initiated graceful shutdown of flow > controller...waiting up to 10 seconds > 2023-07-20 11:12:15,968 INFO [pool-2-thread-2] > o.a.zookeeper.server.ZooKeeperServer shutting down > 2023-07-20 11:12:15,968 INFO [pool-2-thread-2] > o.a.zookeeper.server.RequestThrottler Shutting down > 2023-07-20 11:12:15,968 INFO [RequestThrottler] > o.a.zookeeper.server.RequestThrottler Draining request throttler queue > 2023-07-20 11:12:15,969 INFO [RequestThrottler] > o.a.zookeeper.server.RequestThrottler RequestThrottler shutdown. Dropped 0 > requests > 2023-07-20 11:12:15,969 INFO [pool-2-thread-2] > o.a.z.server.FinalRequestProcessor shutdown of request processor complete > 2023-07-20 11:12:15,977 INFO [pool-2-thread-2] > o.a.z.server.DatadirCleanupManager Shutting down purge task. > 2023-07-20 11:12:16,072 INFO [pool-2-thread-2] > o.apache.nifi.controller.FlowController Controller has been terminated > successfully. > 2023-07-20 11:12:16,083 INFO [pool-2-thread-2] > o.apache.nifi.io.socket.SocketListener Socket Listener has been terminated > successfully. > 2023-07-20 11:12:16,084 INFO [pool-2-thread-2] > o.a.n.w.c.ApplicationStartupContextListener Flow Service shutdown completed > 2023-07-20 11:12:16,084 INFO [pool-2-thread-2] > o.e.j.s.handler.ContextHandler._nifi_api Closing Spring root > WebApplicationContext > 2023-07-20 11:12:16,084 WARN [Cluster Socket Listener] > o.apache.nifi.io.socket.SocketListener Failed to communicate with Unknown > Host due to java.net.SocketException: Socket closed > java.net.SocketException: Socket closed > at java.base/sun.nio.ch.NioSocketImpl.endAccept(NioSocketImpl.java:689) > at java.base/sun.nio.ch.NioSocketImpl.accept(NioSocketImpl.java:762) > at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:675) > at java.base/java.net.ServerSocket.platformImplAccept(ServerSocket.java:641) > at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:617) > at java.base/java.net.ServerSocket.implAccept(ServerSocket.java:574) > at java.base/java.net.ServerSocket.accept(ServerSocket.java:532) > at org.apache.nifi.io.socket.SocketListener$2.run(SocketListener.java:107) > at java.base/java.lang.Thread.run(Thread.java:833) > 2023-07-20 11:12:16,501 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@7c9beb51{nifi-api,/nifi-api,null,STOPPED} > {./work/nar/extensions/nifi-server-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-api-1.22.0.war} > 2023-07-20 11:12:16,709 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@3dfd7eaa{nifi,/nifi,null,STOPPED} > {./work/nar/extensions/nifi-server-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-web-ui-1.22.0.war} > 2023-07-20 11:12:16,719 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@418f0534{nifi-image-viewer,/nifi-image-viewer-1.22.0,null,STOPPED} > {./work/nar/extensions/nifi-image-viewer-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-image-viewer-1.22.0.war} > 2023-07-20 11:12:16,747 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@21f9c6ea{/nifi-update-attribute-ui-1.22.0,/nifi-update-attribute-ui-1.22.0,null,STOPPED} > {./work/nar/extensions/nifi-update-attribute-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-update-attribute-ui-1.22.0.war} > 2023-07-20 11:12:16,760 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@448ade1{nifi-standard-content-viewer,/nifi-standard-content-viewer-1.22.0,null,STOPPED} > {./work/nar/extensions/nifi-standard-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-standard-content-viewer-1.22.0.war} > 2023-07-20 11:12:16,805 INFO [pool-2-thread-2] > o.e.jetty.server.handler.ContextHandler Stopped > o.e.j.w.WebAppContext@5fe46d52{/nifi-jolt-transform-json-ui-1.22.0,/nifi-jolt-transform-json-ui-1.22.0,null,STOPPED} > {./work/nar/extensions/nifi-standard-nar-1.22.0.nar-unpacked/NAR-INF/bundled-dependencies/nifi-jolt-transform-json-ui-1.22.0.war} > 2023-07-20 11:12:16,808 INFO [pool-2-thread-2] > org.apache.nifi.nar.NarAutoLoaderTask Stopping NAR Auto-loader > 2023-07-20 11:12:16,808 INFO [pool-2-thread-2] > org.apache.nifi.nar.NarAutoLoader NAR Auto-Loader stopped > 2023-07-20 11:12:16,809 INFO [pool-2-thread-2] > o.a.n.f.r.CompositeExternalResourceProviderService External Resource Provider > Service is stopped > 2023-07-20 11:12:16,809 INFO [pool-2-thread-2] org.apache.nifi.NiFi > Application Server shutdown completed > {code} > Even though the Nifi app logs prints {{{}Application Server shutdown > completed{}}}, the Java PID is still available and from the bootstrap code it > looks like the stop command monitors the PID and since the PID is still > available it keeps printing the {{Shutdown in }}{{progress}} logs > There are no flows configured and running in the system, Its an empty system > in which we see the issue > Logs and configuration files are attached -- This message was sent by Atlassian Jira (v8.20.10#820010)