Stopping Tomcat 7.x. does NOT stop the Scheduler Service

[GoogleCodeExporter]

Output when STOPPING the Scheduler via GUI and then stopping tomcat.
The 10s timer/wait is implemented by me because its a general suggestion to 
wait a second after shutdown and it shows that he is in the shutdown procedure.
----------------
2012-02-15 10:32:16,570 [http-bio-8080-exec-8] INFO  
org.quartz.core.QuartzScheduler: Scheduler Scheduler_$_NON_CLUSTERED shutting 
down.
2012-02-15 10:32:16,570 [http-bio-8080-exec-8] INFO  
org.quartz.core.QuartzScheduler: Scheduler Scheduler_$_NON_CLUSTERED paused.
2012-02-15 10:32:16,571 [http-bio-8080-exec-8] INFO  
org.quartz.core.QuartzScheduler: Scheduler Scheduler_$_NON_CLUSTERED shutdown 
complete.
2012-02-15 10:32:16,571 [http-bio-8080-exec-8] INFO  
myschedule.service.SchedulerService: Waiting 10s stop stop
2012-02-15 10:32:26,571 [http-bio-8080-exec-8] INFO  
myschedule.service.SchedulerService: Quartz scheduler config 
Scheduler_$_NON_CLUSTERED has been shutdown.
----------------

Just Shutdown Tomcat:
----------------
2012-02-15 10:46:01,660 [pool-2-thread-2] INFO  
myschedule.service.ServiceContainer: Service 
myschedule.service.SchedulerContainer@5867df9 stopped.
2012-02-15 10:46:01,660 [pool-2-thread-2] INFO  
myschedule.service.ServiceContainer: Service 
myschedule.service.SchedulerContainer@5867df9 destroyed.
----------------

As you can see, totally different. Quartz does not get shut down properly.
It has to be hooked into the shutdown process of the Servlet/Webapp.

So it seems
public void shutdownScheduler() is not called on shutdown of the container.

Original issue reported on code.google.com by thomas.h...@gmail.com on 15 Feb 2012 at 9:49

[GoogleCodeExporter]

Its the same as #70 . hg pull did not overwrite ServiceContainer.java even if i 
did not changed anything... So you can close the issue.

Original comment by thomas.h...@gmail.com on 15 Feb 2012 at 11:01

[GoogleCodeExporter]

But i still suggest to put in a slight wait after shutdown, to avoid the Tomcat 
message "that the thread is still there and it could be a memleak".

With this patch, the message does not occur:

SchedulerService.shutdownScheduler():

[...]
scheduler.shutdown(waitForJobsToComplete);
            try {
                Thread.sleep(1000);
            } catch (InterruptedException e) {
                logger.error("Could not sleep!");
            }
[...]

Original comment by thomas.h...@gmail.com on 15 Feb 2012 at 11:20

[GoogleCodeExporter]

Hi Thomas,

Thanks for the notes. As for your last suggestion, the scheduler.shutdown 
nethod should have block until all threads are completed before exit. It's odd 
that your see memleak msg from Tomcat. I will observe this more in future and 
see.

Original comment by saltnlight5 on 18 Feb 2012 at 5:29

[GoogleCodeExporter]

Hello,

I have been having the same problem.  Each time I undeploy the myschedule war 
file it gives the following errors:

Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesJdbc
SEVERE: The web application [/myschedule-2.4.1] registered the JDBC driver 
[com.mysql.jdbc.Driver] but failed to unregister it when the web application 
was stopped. To prevent a memory leak, the JDBC Driver has been forcibly 
unregistered.
Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesThreads
SEVERE: The web application [/myschedule-2.4.1] appears to have started a 
thread named [Timer-6170] but has failed to stop it. This is very likely to 
create a memory leak.
Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesThreads
SEVERE: The web application [/myschedule-2.4.1] appears to have started a 
thread named [Timer-6171] but has failed to stop it. This is very likely to 
create a memory leak.
Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesThreads
SEVERE: The web application [/myschedule-2.4.1] appears to have started a 
thread named [Timer-6172] but has failed to stop it. This is very likely to 
create a memory leak.
Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesThreads
SEVERE: The web application [/myschedule-2.4.1] appears to have started a 
thread named [Timer-6173] but has failed to stop it. This is very likely to 
create a memory leak.
Feb 21, 2012 2:30:23 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesThreads
SEVERE: The web application [/myschedule-2.4.1] appears to have started a 
thread named [Timer-6174] but has failed to stop it. This is very likely to 
create a memory leak.

Hope this helps shed some light on the problem.

Cheers
Tom

Original comment by tomans...@gmail.com on 21 Feb 2012 at 2:37

[GoogleCodeExporter]

Okay, thanks for reporting Tom. I will take a deeper look at this and let you 
guys konw.

~ Zemian

Original comment by saltnlight5 on 24 Feb 2012 at 10:50

[GoogleCodeExporter]

I looked into this little further. The only time I can recreate these errors is 
if I were to shutdown my database while the application is running, and then 
Quartz is having hardtime connecting and thus refusing to shutdown properly. I 
have to think about this little further to find a better solution.

For now, can you guys turn on both myschedule and org.quartz packages in your 
log config, and print me the last section of your shutdown output?

For example, here is my output during a normal shutdown, and you should see 
these:
2012-02-25 10:15:15,379 DEBUG Thread-2 myschedule.service.ServiceContainer:73| 
Stopping service myschedule.service.SchedulerContainer@f7bf2d.
2012-02-25 10:15:15,380 DEBUG Thread-2 
myschedule.service.SchedulerContainer:73| Stopping service 
SchedulerService[configId=a4390505-5fc1-4b76-9c81-7b4aca9f9f8a, 
schedulerName=QuartzScheduler[DatabaseScheduler_$_NON_CLUSTERED]].
2012-02-25 10:15:15,380 INFO  Thread-2 
myschedule.service.SchedulerContainer:75| Service 
SchedulerService[configId=a4390505-5fc1-4b76-9c81-7b4aca9f9f8a, 
schedulerName=QuartzScheduler[DatabaseScheduler_$_NON_CLUSTERED]] stopped.
2012-02-25 10:15:15,380 DEBUG Thread-2 
myschedule.service.SchedulerContainer:73| Stopping service 
SchedulerService[configId=b1548ffb-62ef-4825-91bb-0f38cc4933cc, 
schedulerName=null].
2012-02-25 10:15:15,381 INFO  Thread-2 
myschedule.service.SchedulerContainer:75| Service 
SchedulerService[configId=b1548ffb-62ef-4825-91bb-0f38cc4933cc, 
schedulerName=null] stopped.
2012-02-25 10:15:15,381 INFO  Thread-2 myschedule.service.ServiceContainer:75| 
Service myschedule.service.SchedulerContainer@f7bf2d stopped.
2012-02-25 10:15:15,381 DEBUG Thread-2 myschedule.service.ServiceContainer:73| 
Stopping service myschedule.service.FileConfigStore@12e7234.
2012-02-25 10:15:15,381 INFO  Thread-2 myschedule.service.ServiceContainer:75| 
Service myschedule.service.FileConfigStore@12e7234 stopped.
2012-02-25 10:15:15,381 DEBUG Thread-2 myschedule.service.ServiceContainer:85| 
Destroying service myschedule.service.SchedulerContainer@f7bf2d.
2012-02-25 10:15:15,382 DEBUG Thread-2 
myschedule.service.SchedulerContainer:85| Destroying service 
SchedulerService[configId=a4390505-5fc1-4b76-9c81-7b4aca9f9f8a, 
schedulerName=QuartzScheduler[DatabaseScheduler_$_NON_CLUSTERED]].
2012-02-25 10:15:15,382 DEBUG Thread-2 myschedule.service.SchedulerService:177| 
Shutting down quartz scheduler DatabaseScheduler_$_NON_CLUSTERED with 
waitForJobsToComplete=true
2012-02-25 10:15:15,382 INFO  Thread-2 org.quartz.core.QuartzScheduler:653| 
Scheduler DatabaseScheduler_$_NON_CLUSTERED shutting down.
2012-02-25 10:15:15,382 INFO  Thread-2 org.quartz.core.QuartzScheduler:572| 
Scheduler DatabaseScheduler_$_NON_CLUSTERED paused.
2012-02-25 10:15:15,851 INFO  Thread-2 org.quartz.core.QuartzScheduler:725| 
Scheduler DatabaseScheduler_$_NON_CLUSTERED shutdown complete.
2012-02-25 10:15:15,852 INFO  Thread-2 myschedule.service.SchedulerService:180| 
Quartz scheduler config DatabaseScheduler_$_NON_CLUSTERED has been shutdown.
2012-02-25 10:15:15,852 INFO  Thread-2 
myschedule.service.SchedulerContainer:87| Service 
SchedulerService[configId=a4390505-5fc1-4b76-9c81-7b4aca9f9f8a, 
schedulerName=null] destroyed.
2012-02-25 10:15:15,852 DEBUG Thread-2 
myschedule.service.SchedulerContainer:85| Destroying service 
SchedulerService[configId=b1548ffb-62ef-4825-91bb-0f38cc4933cc, 
schedulerName=null].
2012-02-25 10:15:15,853 INFO  Thread-2 
myschedule.service.SchedulerContainer:87| Service 
SchedulerService[configId=b1548ffb-62ef-4825-91bb-0f38cc4933cc, 
schedulerName=null] destroyed.
2012-02-25 10:15:15,853 INFO  Thread-2 myschedule.service.ServiceContainer:87| 
Service myschedule.service.SchedulerContainer@f7bf2d destroyed.
2012-02-25 10:15:15,853 DEBUG Thread-2 myschedule.service.ServiceContainer:85| 
Destroying service myschedule.service.FileConfigStore@12e7234.
2012-02-25 10:15:15,853 INFO  Thread-2 myschedule.service.ServiceContainer:87| 
Service myschedule.service.FileConfigStore@12e7234 destroyed.
2012-02-25 10:15:15,853 INFO  Thread-2 myschedule.web.WebAppContextListener:39| 
Web application destroyed.

Original comment by saltnlight5 on 25 Feb 2012 at 3:23

[GoogleCodeExporter]

@Tom,
I see some of your shutdown error is caused by a "Timer" thread is still 
running. Are you creating Timer objects in your jobs? The only place that a 
Timer thread gets created is by Quartz if you don't set 
"org.quartz.scheduler.skipUpdateCheck = true", else it won't be created at all. 
I am just curious where it comes from.

Original comment by saltnlight5 on 25 Feb 2012 at 3:26

[GoogleCodeExporter]

I also did a little research on the following error(it's more of a warning than 
error):

Feb 25, 2012 11:11:14 AM org.apache.catalina.loader.WebappClassLoader 
clearReferencesJdbc
SEVERE: The web application [/myschedule-2.4.2-SNAPSHOT] registered the JDBC 
driver [com.mysql.jdbc.Driver] but failed to unregister it when the web 
application was stopped. To prevent a memory leak, the JDBC Driver has been 
forcibly unregistered.

My notes are:

1) This is Tomcat message saying that the JDBC is not doing its job to 
unregister itself, and so it's doing the job for it! Good to have, and will 
stay unless JDBC vendor fix their stuff. It's more of a warning and safe to 
ignore.

2) This msg only shows if you package JDBC jar into myschedule.war:WEB-INF/lib 
folder. You can install the JDBC jar into $TOMCAT_HOME/lib instead, and it will 
only loaded once, and thus the msg will not show when you undeploy the war 
only. I personally prefer you load the JDBC jar into the $TOMCAT_HOME/lib in 
general anyway.

3) This msg is only started on tomcat-6.0.24 and higher, as part of their mem 
leak detection code.

Original comment by saltnlight5 on 25 Feb 2012 at 4:21

[GoogleCodeExporter]

As i said before:
This is well known behaviour of quartz/spring and tomcat.

In quartz and spring forum this is discussed quite often, tomcat shuts down too 
fast for quartz so tomcat thinks that are still objects/resources referenced 
and shows the error and has sometimes problems to shut the instance down.

The solution is also well documented:
Wait 1000ms after shutdown command....
http://forums.terracotta.org/forums/posts/list/3479.page

I am using the Thread.sleep approach in a productive environment and it works 
well.

Original comment by thomas.h...@gmail.com on 25 Feb 2012 at 5:02

[GoogleCodeExporter]

Okay, thank you Thomas.

I have added this option in MySchedule in rev 034d6ca8546c.

Because this is server specific, I added this in such that you can configure 
the amount of pause time using 
"-Dmyschedule.config=classpath:myschedule/cutom-myschedule-config.properties". 
The defult is 1000ms. In the logout, you will see something like this:
  2012-02-26 16:45:49,912 INFO  Thread-1 myschedule.web.WebAppContextListener:39| Web application destroyed.
  2012-02-26 16:45:49,912 INFO  Thread-1 myschedule.web.WebAppContextListener:45| Pausing 1000ms after sheduler shutdown to avoid server problem.

You will get this on next release.

Original comment by saltnlight5 on 26 Feb 2012 at 9:51

[GoogleCodeExporter]

@saltnlight5

Concerning the Timer threads, I am not creating any in my jobs.  To be honest I 
don't even know what they are.  I only create jobs and triggers.  That's all.

Original comment by tomans...@gmail.com on 27 Feb 2012 at 1:49

[GoogleCodeExporter]

fixed in Release-2.4.2

Original comment by saltnlight5 on 21 Mar 2012 at 3:39

• Changed state: Fixed
• Added labels: Release-2.4.2