Support Questions
Find answers, ask questions, and share your expertise

NiFi is failing to shutdown gracefully. How to debug?

NiFi is failing to shutdown gracefully. How to debug?

New Contributor

Hi,

we are running a NiFi cluster and it fails to shutdown.
After analyzing thread dumps taken during the shutdown period and improving shutdown of our own custom processors we are now stuck.

Excluding daemon and JVM threads, the only threads that are now left are all "Timer-Driven Process Thread-X" threads. So I guess they are not being shutdown correctly. I'm going to attach a full thread dump to this post. ( nifi-threads-during-shutdown.txt) (We have a lot of IO-bound processes, that's why we have an unusually high amount of threads.) The other dominant thread type is distributed map cache server. But they are daemon threads and should not hold the JVM from exiting if I understand correctly.


None of the threads do anything but wait. Here is one of their traces:

"Timer-Driven Process Thread-69" #193 prio=5 os_prio=0 tid=0x00007f30d8002000 nid=0x5c7e waiting on condition [0x00007f30269e6000]
   java.lang.Thread.State: WAITING (parking)
	at sun.misc.Unsafe.park(Native Method)
	- parking to wait for  <0x00007f31cfc1b190> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

What increases the difficulty of these shutdown issues is that the logging threads are already shutdown and the last log lines in the nifi-app.log are the ones about shutting down jetty web server stuff. After that there are many log statements in the code that are very much run (the flow is being stopped for example). But the logging output doesn't end up in the file anymore:

nifi-app_2018-03-27_15.0.log:2018-03-27 15:49:07,070 INFO [pool-2-thread-2] org.apache.nifi.BootstrapListener Received SHUTDOWN request from Bootstrap
nifi-app_2018-03-27_15.0.log:2018-03-27 15:49:07,070 INFO [pool-2-thread-2] org.apache.nifi.NiFi Initiating shutdown of Jetty web server...
nifi-app_2018-03-27_15.0.log-2018-03-27 15:49:07,074 INFO [pool-2-thread-2] o.eclipse.jetty.server.AbstractConnector Stopped ServerConnector@99e68b5{HTTP/1.1,[http/1.1]}{smtp03.abusix.net:9090}
nifi-app_2018-03-27_15.0.log-2018-03-27 15:49:07,077 INFO [pool-2-thread-2] org.eclipse.jetty.server.session Stopped scavenging
nifi-app_2018-03-27_15.0.log-2018-03-27 15:51:20,411 INFO [main] org.apache.nifi.NiFi Launching NiFi...

The nifi-bootstrap.log only shows that it's waiting for the nifi process to finish shutting down and in the end it ends up killing it (after waiting for the configured graceful period that we extended to one minute, just to make sure we give it enough time):
2018-03-27 16:08:34,525 INFO [main] org.apache.nifi.bootstrap.Command Apache NiFi has accepted the Shutdown Command and is shutting down now
2018-03-27 16:08:34,533 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:36,541 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:38,546 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:40,555 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:42,564 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:44,573 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:46,582 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:48,587 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:50,595 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:52,603 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:54,618 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:56,629 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:08:58,634 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:00,641 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:02,650 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:04,657 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:06,666 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:08,677 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:10,684 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:12,689 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:14,703 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:16,715 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:18,724 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:20,732 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:22,740 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:24,763 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:26,783 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:28,792 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:30,800 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:32,809 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:34,813 INFO [main] org.apache.nifi.bootstrap.Command Waiting for Apache NiFi to finish shutting down...
2018-03-27 16:09:34,817 WARN [main] org.apache.nifi.bootstrap.Command NiFi has not finished shutting down after 60 seconds. Killing process.
2018-03-27 16:09:34,821 INFO [main] org.apache.nifi.bootstrap.Command NiFi has finished shutting down.

We are running HDF 3.1 with Nifi 1.5.0.

What can I do to further invesigate what's wrong here? I tried to look through the nifi source code to see if it's stuck somewhere. But since there is not shutdown thread left in the dump, I think it actually runs through or fails with an error, that is not logged due to the problem above. Thank you very much for your time!

1 REPLY 1

Re: NiFi is failing to shutdown gracefully. How to debug?

New Contributor

Facing similar problem. Were you able to solve this?