Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memory Leak when using JsonSchemaValidator with Tomcat 7 #135

Open
KarstenHoehne opened this issue Dec 18, 2014 · 24 comments
Open

Memory Leak when using JsonSchemaValidator with Tomcat 7 #135

KarstenHoehne opened this issue Dec 18, 2014 · 24 comments

Comments

@KarstenHoehne
Copy link

I wanted to use JsonSchemaValidator on a Tomcat application (Tomcat 7.0.55).
I have noticed that Tomcat logs a SEVERE error about memory leaks. I could reproduce this with the following simple setup:

Netbeans 8:
New Project > Maven > Web Applikation
Use Apache Tomcat as Server; Use Java 7 EE Web as Java Version

Add JsonSchemaValidator to the projects POM
Create a new Java Class:

@WebListener
public class StartUp implements ServletContextListener {

    @Override
    public void contextInitialized(ServletContextEvent sce) {
        System.out.println("Start");
        JsonSchemaFactory factory = JsonSchemaFactory.byDefault();
    }

    @Override
    public void contextDestroyed(ServletContextEvent sce) {
        System.out.println("Stop");
    }

}

Build the Applikation
Run/Deploy the Appliaktion
Clean/Undeploy the Applikation

Tomcat will log the following error:

SEVERE: The web application [/testApp] appears to have started a thread named [pool-1-thread-1] but has failed to stop it. This is very likely to create a memory leak.

The problem seems to correspond to this Tomcat Wiki Entry:
http://wiki.apache.org/tomcat/MemoryLeakProtection#cclThreadSpawnedByWebApp

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

Hello,

Do you have any more information?

The only thing which potentially spawns threads in this package is the LoadingCache used to cache JSON Reference lookups... Not sure I have the means to rename the threads it generates.

Also, if possible, can you do a kill -3 on the JVM when this "webapp" runs and post the thread dump?

@KarstenHoehne
Copy link
Author

Ok did a thread dump (results below).

The Thread names are (as far as I can tell) generated by Tomcats Executor
http://tomcat.apache.org/tomcat-7.0-doc/config/executor.html
http://stackoverflow.com/questions/7552570/what-are-those-java-threads-starting-with-pool

I really don't know more. Just that somewhere JsonValidator and Tomcat clash

Thread Dump:
2014-12-18 11:05:04
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.20-b23 mixed mode):

"pool-1-thread-6" #35 daemon prio=5 os_prio=0 tid=0x00007f670c28e800 nid=0x1b4a waiting on condition [0x00007f674e54b000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000864bebc8> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"pool-1-thread-5" #34 daemon prio=5 os_prio=0 tid=0x00007f670c28b000 nid=0x1b49 waiting on condition [0x00007f674e64c000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000864bebc8> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"pool-1-thread-4" #33 daemon prio=5 os_prio=0 tid=0x00007f670c28a800 nid=0x1b48 waiting on condition [0x00007f674e74d000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000864bebc8> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"pool-1-thread-3" #32 daemon prio=5 os_prio=0 tid=0x00007f670c1c9800 nid=0x1b47 waiting on condition [0x00007f674ea4e000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000862a2060> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"pool-1-thread-2" #31 daemon prio=5 os_prio=0 tid=0x00007f670c1c8000 nid=0x1b46 waiting on condition [0x00007f674eb4f000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000862a2060> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"pool-1-thread-1" #30 daemon prio=5 os_prio=0 tid=0x00007f670c1c6800 nid=0x1b45 waiting on condition [0x00007f674ec50000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000862a2060> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
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)

"http-bio-8080-exec-10" #29 daemon prio=5 os_prio=0 tid=0x00007f673c127000 nid=0x1b43 waiting on condition [0x00007f674ffd8000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-9" #28 daemon prio=5 os_prio=0 tid=0x00007f6734008800 nid=0x1b42 waiting on condition [0x00007f674fed7000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-8" #27 daemon prio=5 os_prio=0 tid=0x00007f670c001000 nid=0x1b3a waiting on condition [0x00007f674edca000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-7" #26 daemon prio=5 os_prio=0 tid=0x00007f6734006800 nid=0x1b39 waiting on condition [0x00007f674eecb000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-6" #25 daemon prio=5 os_prio=0 tid=0x00007f6714001000 nid=0x1b38 waiting on condition [0x00007f674efcc000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-5" #24 daemon prio=5 os_prio=0 tid=0x00007f6734005000 nid=0x1b37 waiting on condition [0x00007f674f0cd000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-4" #23 daemon prio=5 os_prio=0 tid=0x00007f671c001000 nid=0x1b36 waiting on condition [0x00007f674f1ce000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-3" #22 daemon prio=5 os_prio=0 tid=0x00007f6734003000 nid=0x1b35 waiting on condition [0x00007f674f2cf000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-2" #21 daemon prio=5 os_prio=0 tid=0x00007f67240ae800 nid=0x1b34 waiting on condition [0x00007f674f3d0000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-exec-1" #20 daemon prio=5 os_prio=0 tid=0x00007f6734001800 nid=0x1b33 waiting on condition [0x00007f674f6d1000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000863fa348> (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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
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 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

"ajp-bio-8009-AsyncTimeout" #18 daemon prio=5 os_prio=0 tid=0x00007f679c4f3000 nid=0x1b32 waiting on condition [0x00007f674f7d2000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.tomcat.util.net.JIoEndpoint$AsyncTimeout.run(JIoEndpoint.java:152)
at java.lang.Thread.run(Thread.java:745)

"ajp-bio-8009-Acceptor-0" #17 daemon prio=5 os_prio=0 tid=0x00007f679c4f1800 nid=0x1b31 runnable [0x00007f674f8d3000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:60)
at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:220)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-AsyncTimeout" #16 daemon prio=5 os_prio=0 tid=0x00007f679c4f0000 nid=0x1b30 waiting on condition [0x00007f674f9d4000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.tomcat.util.net.JIoEndpoint$AsyncTimeout.run(JIoEndpoint.java:152)
at java.lang.Thread.run(Thread.java:745)

"http-bio-8080-Acceptor-0" #15 daemon prio=5 os_prio=0 tid=0x00007f679c4ee000 nid=0x1b2f runnable [0x00007f674fad5000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at org.apache.tomcat.util.net.DefaultServerSocketFactory.acceptSocket(DefaultServerSocketFactory.java:60)
at org.apache.tomcat.util.net.JIoEndpoint$Acceptor.run(JIoEndpoint.java:220)
at java.lang.Thread.run(Thread.java:745)

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" #14 daemon prio=5 os_prio=0 tid=0x00007f679c4eb800 nid=0x1b2e waiting on condition [0x00007f674fbd6000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1513)
at java.lang.Thread.run(Thread.java:745)

"GC Daemon" #11 daemon prio=2 os_prio=0 tid=0x00007f679c45f000 nid=0x1b2b in Object.wait() [0x00007f67847a0000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000008516ac28> (a sun.misc.GC$LatencyLock)
at sun.misc.GC$Daemon.run(GC.java:117)
- locked <0x000000008516ac28> (a sun.misc.GC$LatencyLock)

"Service Thread" #8 daemon prio=9 os_prio=0 tid=0x00007f679c0b8000 nid=0x1b29 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C1 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f679c0b2800 nid=0x1b28 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f679c0b1000 nid=0x1b27 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f679c0ae000 nid=0x1b26 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f679c0ac000 nid=0x1b25 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f679c07d000 nid=0x1b23 in Object.wait() [0x00007f6786022000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000008516bb38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:142)
- locked <0x000000008516bb38> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:158)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f679c07b000 nid=0x1b22 in Object.wait() [0x00007f6786123000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x000000008516bb78> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:502)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:157)
- locked <0x000000008516bb78> (a java.lang.ref.Reference$Lock)

"main" #1 prio=5 os_prio=0 tid=0x00007f679c00a800 nid=0x1b1b runnable [0x00007f67a2b00000]
java.lang.Thread.State: RUNNABLE
at java.net.PlainSocketImpl.socketAccept(Native Method)
at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:404)
at java.net.ServerSocket.implAccept(ServerSocket.java:545)
at java.net.ServerSocket.accept(ServerSocket.java:513)
at org.apache.catalina.core.StandardServer.await(StandardServer.java:453)
at org.apache.catalina.startup.Catalina.await(Catalina.java:777)
at org.apache.catalina.startup.Catalina.start(Catalina.java:723)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:321)
at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:455)

"VM Thread" os_prio=0 tid=0x00007f679c073800 nid=0x1b21 runnable

"GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007f679c01f800 nid=0x1b1c runnable

"GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007f679c021800 nid=0x1b1d runnable

"GC task thread#2 (ParallelGC)" os_prio=0 tid=0x00007f679c023000 nid=0x1b1e runnable

"GC task thread#3 (ParallelGC)" os_prio=0 tid=0x00007f679c025000 nid=0x1b1f runnable

"VM Periodic Task Thread" os_prio=0 tid=0x00007f679c0ba800 nid=0x1b2a waiting on condition

JNI global references: 92

Heap
PSYoungGen total 536064K, used 44065K [0x00000000d7000000, 0x00000000faa00000, 0x0000000100000000)
eden space 497664K, 8% used [0x00000000d7000000,0x00000000d9b08518,0x00000000f5600000)
from space 38400K, 0% used [0x00000000f7e80000,0x00000000f7e80000,0x00000000fa400000)
to space 41472K, 0% used [0x00000000f5600000,0x00000000f5600000,0x00000000f7e80000)
ParOldGen total 98816K, used 44833K [0x0000000085000000, 0x000000008b080000, 0x00000000d7000000)
object space 98816K, 45% used [0x0000000085000000,0x0000000087bc8470,0x000000008b080000)
Metaspace used 26601K, capacity 26990K, committed 27136K, reserved 1073152K
class space used 2896K, capacity 3022K, committed 3072K, reserved 1048576K

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

Uh, no elements in any thread stack trace shows any code related to json-schema-validator :(

This one is going to be a PITA to debug...

@KarstenHoehne
Copy link
Author

yep very strange error indeed ...

@KarstenHoehne
Copy link
Author

I switched over to tomcat 8.0.15 just to see if that changes anything.
The Log messages now appear as WARNING instead of SEVERE. And the thread dump for the thread gets printed automatically;

18-Dec-2014 11:43:02.922 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
18-Dec-2014 11:43:02.923 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-2] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
18-Dec-2014 11:43:02.923 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-3] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
18-Dec-2014 11:43:02.924 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-4] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
18-Dec-2014 11:43:02.927 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-5] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)
18-Dec-2014 11:43:02.928 WARNING [http-nio-8080-exec-12] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [testApp] appears to have started a thread named [pool-2-thread-6] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
sun.misc.Unsafe.park(Native Method)
java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
java.lang.Thread.run(Thread.java:745)

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

Still no trace from -validator. Argh.

OK well, since I don't create any ThreadPool by myself it has to be LoadingCache.

I'll try and investigate on this front and see what can be done. From a cursory look however, it does not seem that there is a way to control its pool...

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

Ah, I found something interesting:

https://code.google.com/p/guava-libraries/issues/detail?id=517

And the bug is quite recent, too. Seems like I was on the right track.

@KarstenHoehne
Copy link
Author

yes this seems to be the right direction. ANother Bug report dealing with memory leaks related to LoadingCache:
google/guava#1837

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

One thing I'm going to try is using this instead of a LoadingCache; it is well written and tested. But there is one issue which I'd like to see fixed before that...

@ddossot
Copy link

ddossot commented Dec 18, 2014

What about jolly good old EHCache? It has all sort of expiration strategies and is very stable.

@fge
Copy link
Collaborator

fge commented Dec 18, 2014

@ddossot I had considered it at the very beginning -- until I stumbled upon Guava.

Well, this has been a loong time now (nearly 2 years), and my first impression of ehcache was not very good; in particular, I recall a very complicated configuration for a simple cache and that keys and values had to implement Serializable, of which I think as little as this guy...

Well, I guess I can try again.

@ddossot
Copy link

ddossot commented Dec 18, 2014

Yeah, the config side of things of ehcache could be a little off putting. Regarding serializable key/values, this requirement has been lifted since version 1.2 (see http://ehcache.org/apidocs/2.6.9/index.html?net/sf/ehcache/Element.html ).

@KarstenHoehne
Copy link
Author

any news on this? The issue in the other framework that you wanted to see fixed has been marked as closed:
jhalterman/expiringmap#5

@huggsboson
Copy link
Member

We are hitting an issue with a seeming leak. When I do a jmap the dump strongly indicates the cache used by json-schema-validator/cores are the primary cause. A colleague of mine pointed out that maximumSize isn't being set on any of the caches as a possible culprit. This may be a seperate issue from the main one in this thread but it seemed worth starting here.

Also the majority of the items that are filling the cache are ProcessingResults (a guava cache is used there as well) and also doesn't have a max size. I assume both are leaking but we have way more ProcessingResults.

Thoughts?

@idelvall
Copy link

Hi guys, thanks to Tomcat I am here too, but the truth is the issue has nothing to do with it. Debugging a simple application with the previous code snippet is enough to see these threads are being started too.

Here is the stack at the point where the executor is executed:

java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1333)
com.github.fge.msgsimple.provider.LoadingMessageSourceProvider.getMessageSource(LoadingMessageSourceProvider.java:190)
com.github.fge.msgsimple.bundle.MessageBundle.getMessage(MessageBundle.java:122)
com.github.fge.msgsimple.bundle.MessageBundle.getMessage(MessageBundle.java:146)
com.github.fge.jackson.JsonNodeReader.readNode(JsonNodeReader.java:140)
com.github.fge.jackson.JsonNodeReader.fromInputStream(JsonNodeReader.java:103)
com.github.fge.jackson.JsonLoader.fromResource(JsonLoader.java:99)
com.github.fge.jsonschema.SchemaVersion.<init>(SchemaVersion.java:63)
com.github.fge.jsonschema.SchemaVersion.<clinit>(SchemaVersion.java:44)
sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:483)
java.lang.Class.getEnumConstantsShared(Class.java:3209)
java.lang.System$2.getEnumConstantsShared(System.java:1246)
java.util.EnumMap.getKeyUniverse(EnumMap.java:752)
java.util.EnumMap.<init>(EnumMap.java:138)
com.google.common.collect.Maps.newEnumMap(Maps.java:337)
com.github.fge.jsonschema.cfg.ValidationConfigurationBuilder.<clinit>(ValidationConfigurationBuilder.java:62)
com.github.fge.jsonschema.cfg.ValidationConfiguration.newBuilder(ValidationConfiguration.java:92)
...

being the issue in this class: com/github/fge/msgsimple/provider/LoadingMessageSourceProvider

/*
* Use daemon threads. We don't give control to the user about the
* ExecutorService, and we don't have a reliable way to shut it down (a JVM
* shutdown hook does not get involved on a webapp shutdown, so we cannot
* use that...).
*/

@idelvall
Copy link

idelvall commented Jan 13, 2016

Maybe the author can give us a hint on why using multithreading here?

@anantonugroho
Copy link

Hi, I have similar issue, why this is mark as closed? I am using 2.2.6.

I only added this following code and it started a ThreadPool with no way to closed it.
JsonSchemaFactory factory = JsonSchemaFactory.byDefault();

Thanks to @idelvall have managed to track down until get LoadingMessageSourceProvider

Any updates on this issue ?

@mvrajumca
Copy link

mvrajumca commented Dec 7, 2017

Hi, any update on this. I can see the validator classes are initializing the thread pool and threads are not getting terminated during the app reload in Tomcat. Is anyone facing this issue with 2.2.6 version? @fge @ddossot @idelvall

@idelvall
Copy link

idelvall commented Dec 8, 2017

This change worked for me: brutusin/json-provider@338c723

Just add this class to your source code, and try, the class loader should resolve to this class definition instead of the original one

@mvrajumca
Copy link

@idelvall Thanks for the response. I will try it out.
@fge Could you please let me know if there will be an issue with not using the thread pools? If yes it would be nice if we have an option to enable the threadpool executors conditionally as some of the apps need the cleaner way to shutdown the daemon threads.

@febpetroni
Copy link

I can confirm this issue, json-schema-validator is flooding my memory with cached ProcessingResults and alikes. I tried @idelvall 's fix to no avail. Is anyone looking into this?

@huggsboson
Copy link
Member

@mvrajumca @febpetroni this should be fixed in group: "com.github.java-json-tools", name: "json-schema-validator", version: "2.2.8".

Context: @fge has stepped away from the project. I own the github page now, but can't publish to his old maven central group. That's why the group moved.

@huggsboson
Copy link
Member

Or at least the thing that @febpetroni talked about is fixed in 2.2.8. It is a cache with unbounded size growing over time.

@lliangbin
Copy link

@huggsboson I am using version 2.2.8 json-schema-validator, I also found memory leak exists. I using eclipse MAT found that the biggest objects is com.google.common.cache.LocalCache$LocalLoadingCache about 200M.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

9 participants