Dheeraj Joshi created NIFI-11841:
------------------------------------
Summary: 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
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)
