Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Application takes very long to terminate

We have writen a console application (will be used as service) that starts several worker threads for handling requests coming in via mina. The application leaves the main loop when a stop signal is received on a specific network port. This is the intended way of stoping the service. That works quite ok, but when the stop signal is received the process of the application does not terminate immediatly (takes up to 5 minutes). We verified via log messages that the main function is left quickly and as expected and all threads created by the application are also terminated. But the application keeps on running.

The threads still running before leaving the main function are:

Signal Dispatcher (java.lang.Thread)
Finalizer (java.lang.ref.Finalizer$FinalizerThread)
Abandoned connection cleanup thread (com.mysql.jdbc.AbandonedConnectionCleanupThread)
main (java.lang.Thread)
pool-2-thread-1 (java.lang.Thread)
Reference Handler (java.lang.ref.Reference$ReferenceHandler)

We are currently using the following java version:

java version "1.7.0_80"
Java(TM) SE Runtime Environment (build 1.7.0_80-b15)
Java HotSpot(TM) 64-Bit Server VM (build 24.80-b11, mixed mode)

The operation system is ubuntu 14.04 LTS.

I have no clue about this behaviour and i hope for some hints on how to investigate that problem further.

Addtional Information

I have produced a Full thread dump as suggested. Four threads are waiting:

"pool-2-thread-1" prio=10 tid=0x00007fd7fc51f000 nid=0x16200 waiting on condition [0x00007fd800318000]
   java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000cceaf660> (a java.util.concurrent.SynchronousQueue$TransferStack)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
    at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)
    at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:942)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
    at java.lang.Thread.run(Thread.java:745)

"Abandoned connection cleanup thread" daemon prio=10 tid=0x00007fd7fc23d800 nid=0x161e2 in Object.wait() [0x00007fd800cbb000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000dc2af720> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000dc2af720> (a java.lang.ref.ReferenceQueue$Lock)
    at com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:41)

"Finalizer" daemon prio=10 tid=0x00007fd7fc066000 nid=0x161d6 in Object.wait() [0x00007fd801bd6000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000dc03c060> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
    - locked <0x00000000dc03c060> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" daemon prio=10 tid=0x00007fd7fc064000 nid=0x161d5 in Object.wait() [0x00007fd801cd7000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00000000dc03c108> (a java.lang.ref.Reference$Lock)
    at java.lang.Object.wait(Object.java:503)
    at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
    - locked <0x00000000dc03c108> (a java.lang.ref.Reference$Lock)

Can someone confirm, that I should investigate towards pool-2-thread-1? I'm unsure how to interpret the result.

Solution In the end a call to acceptor.dispose (MINA) did the trick...

like image 294
user331471 Avatar asked May 08 '15 09:05

user331471


1 Answers

My guess is you have created an ExecutorService which is running as a non daemon. This means that if you don't shutdown() this pool it will keep the application running until it stops the thread gracefully (as it has been used for a number of minutes)

You can create an ExecutorService with daemon threads to make it clear the application doesn't need to wait for this thread pool to stop. (Or you can shut it down explicitly)

String poolName = ....
exec = Executors.newCachedThreadPool(r -> {
    Thread t = new Thread(r, poolName);
    t.setDaemon(true);
    return t;
});

pool-2-thread-1 is nothing that we created intentionally

This could be created by a library, but it follows the form of an ExecutorService. Note: it is pool-2.. indicating it is not the first pool the application creates.

You can force non-system threads to die by using System.exit(0); This is not ideal as the threads might be doing useful work if they were made non-daemon for a good reason, but if the thread is started by a 3rd party library, it might be your simplest option.


Something you could try is tracing where all a Threads are created. One way is to use the debugger to break point the constructor of the ThreadPoolExecutor or any other key method which would show you where the pool is being created.

Or you can use a memory profiler with allocation tracing. Then look at where every Thread object is created.

Another option is to modify the Thread class to include a stack trace of where it was created (or started) You can do this by building you own version and pre-pending it to the boot class path.

like image 59
Peter Lawrey Avatar answered Oct 23 '22 16:10

Peter Lawrey