You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@nifi.apache.org by "Michael W Moser (Jira)" <ji...@apache.org> on 2025/10/21 18:24:00 UTC
[jira] [Commented] (NIFI-11841) Nifi in cluster setup doesn't stop within the graceful shutdown period
[ https://issues.apache.org/jira/browse/NIFI-11841?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18031508#comment-18031508 ]
Michael W Moser commented on NIFI-11841:
----------------------------------------
Since I typically advise people to avoid using embedded Zookeeper, looking into this ticket remains near the bottom of my TODO list.
> 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: Logs.zip, 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)