scheduled task errors when shutting down tomcat

Description

when I shutdown the latest snapshot, I'm seeing all these errors, it's been happening with previous 5.3 snapshots too

just starting lucee, opening one page on the virtual host and then stopping the service triggers all these error messages

26-Sep-2018 15:00:17.942 INFO [Thread-76] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8888"] 26-Sep-2018 15:00:18.531 INFO [Thread-76] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["ajp-nio-8009"] 26-Sep-2018 15:00:19.107 INFO [Thread-76] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina] 26-Sep-2018 15:00:19.134 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-10] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.136 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-12] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.138 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-13] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.139 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-14] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.140 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-15] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.141 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-16] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.142 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-17] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.143 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-18] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.145 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-19] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.146 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-20] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.147 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-21] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.148 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-22] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.149 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-23] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.150 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-24] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.151 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-25] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.153 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-26] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.154 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-27] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.155 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-28] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.156 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-29] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Thread.sleep(Native Method) lucee.runtime.schedule.ScheduledTaskThread.sleepEL(ScheduledTaskThread.java:174) lucee.runtime.schedule.ScheduledTaskThread._run(ScheduledTaskThread.java:123) lucee.runtime.schedule.ScheduledTaskThread.run(ScheduledTaskThread.java:82) 26-Sep-2018 15:00:19.158 WARNING [lucee-localhost-httpd-confl556-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [Thread-30] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread: java.lang.Object.wait(Native Method) lucee.runtime.spooler.SpoolerEngineImpl$SpoolerThread.doWait(SpoolerEngineImpl.java:510) lucee.runtime.spooler.SpoolerEngineImpl$SpoolerThread.run(SpoolerEngineImpl.java:480) 26-Sep-2018 15:00:25.017 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.018 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.020 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.021 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.022 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.023 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.024 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-7] 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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.025 WARNING [127.0.0.1-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [ROOT] appears to have started a thread named [FelixResolver-8] 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.parkNanos(LockSupport.java:215) java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) java.util.concurrent.LinkedBlockingQueue.poll(LinkedBlockingQueue.java:467) java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) java.lang.Thread.run(Thread.java:748) 26-Sep-2018 15:00:25.033 INFO [Thread-76] org.apache.coyote.AbstractProtocol.stop Stopping ProtocolHandler ["http-nio-8888"]

Environment

Apache Tomcat/8.5.31
JVM 1.8.0_181-b13
5.3.1.74-SNAPSHOT

Attachments

1
  • 28 Sept 2018, 08:30 am

relates to

Activity

Show:

Vikrant 13 May 2019 at 18:59

After deleting scheduled task it still runs. Currently I had to delete the whole web-inf folder. IIS recreates the folder and problem gone. Looks like caching issue. Please fix it. If I am not wrong this also causes to create duplicate task runs.

Michael Offner 8 April 2019 at 22:40

Pothys - MitrahSoft 5 April 2019 at 07:53

,

Thanx for your info!

Michael Offner 5 April 2019 at 07:42

correction, don't open new tickets, thinking about this, i don't think this is a bug at all.
i think felix simply is waiting that the Lucee core is shutting down. so a resultant problem.

But that could suggest that the core actually tries to stop that ST but is not able to do. threads that are in "native code" cannot be stopped at all in Java bytecode. in any case there is no actual harm, when the task is done, it will die anyway, because he has set a flag to stop.
In any case the log will give us more inside.

Michael Offner 5 April 2019 at 07:28

No, we cannot reopen the ticket, we can clone this ticket and handle it as a new ticket.

Of the 3 stacktrace posted above, 2 are unrelated to this ticket and should be handled in a different ticket ( please open 2 tickets for them).
1) actually is a scheduled task hanging
2) is a thread from Felix "hanging", most likely because the reset process is still running
3) Is most likely a log file having a break atm between working, flush data from buffer to file

the fix should in a proper shutdown check for open task and shut them down, it was working fine in my tests.
I will add some logging, so we see what is going on.

Fixed

Details

Assignee

Reporter

Priority

Fix versions

New Issue warning screen

Before you create a new Issue, please post to the mailing list first https://dev.lucee.org

Once the issue has been verified, one of the Lucee team will ask you to file an issue

Sprint

Affects versions

Created 26 September 2018 at 13:06
Updated 8 May 2020 at 18:44
Resolved 28 March 2019 at 14:03

Flag notifications