Quartz job runs twice when deployed on tomcat 6/Ubuntu 10.04LTS

Question

I run a Spring Framework/SmartGWT based web-app, with now an added Quartz job. The job is supposed to run every day at 2am, and picks winners from a DB table. From my logs I see it runs twice, concurrently it seems, because as you can see, the logs overlap:

Generating winners of yesterday...
Generating winners of yesterday...
winning id's: 15
done, mail queue is filled.

winning id's: 18
done, mail queue is filled.

My applicationContext.xml looks like this:

<!-- initiates and calls the job -->  
<beans:bean id="GenerateWinnersAndFillMailingQueueJobDetail" class="org.springframework.scheduling.quartz.MethodInvokingJobDetailFactoryBean"> 
  <beans:property name="targetObject" ref="GenerateWinnersAndFillMailingQueueJobExecutor"/>  
  <beans:property name="targetMethod" value="execute"/> 
</beans:bean>  
<!-- here's where we use the Cron like scheduling expression      to define when the bean is run. -->  
<beans:bean id="GenerateWinnersAndFillMailingQueueJob" class="org.springframework.scheduling.quartz.CronTriggerBean"> 
  <beans:property name="jobDetail" ref="GenerateWinnersAndFillMailingQueueJobDetail"/>  
  <!-- run every morning at 2AM -->  
  <beans:property name="cronExpression" value="0 0 2 * * ?"/> 
</beans:bean> 
... another quartz jobs is defined here, omitted for clarity ...
<beans:bean class="org.springframework.scheduling.quartz.SchedulerFactoryBean"> 
  <beans:property name="triggers"> 
    <beans:list> 
      <beans:ref bean="GenerateWinnersAndFillMailingQueueJob"/>  
      <beans:ref bean="SendEmailsFromMailQueueJob"/> 
    </beans:list> 
  </beans:property> 
</beans:bean> 

I don't really see what is wrong here, it is a pretty simple use case. When I test this locally, on the server that comes with GWT development mode, it DOES work. Only when deploying to Tomcat6 on Ubuntu 10.04 LTS, I get this issue.

Any ideas?

** edit: after a hint from the comments, increasing the log level, it seems that Spring is running twice. Restarting the tomcat server shows that two Springs are instantiated, about 4 seconds apart.

2011-08-29 08:49:22,567 {ABSOLUTE}  INFO XmlWebApplicationContext,Thread-9:1002 - Closing Root WebApplicationContext: startup date [Sun Aug 28 20:53:39 CEST 2011]; root of context hierarchy
2011-08-29 08:49:22,569 {ABSOLUTE}  INFO DefaultLifecycleProcessor,Thread-9:345 - Stopping beans in phase 2147483647
2011-08-29 08:49:22,589 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:537 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED paused.
2011-08-29 08:49:22,592 {ABSOLUTE}  INFO DefaultListableBeanFactory,Thread-9:422 - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@12e14ebc: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,MerchantSimpleJsonWebservice,merchantDao,AdvertisementSimpleJsonWebservice,advertisementDao,ContactFormSubmitsSimpleJsonWebservice,contactFormSubmitsDao,PlayerCustomJsonWebservice,PlayerCustomJsonWebserviceImpl,submitSolutionDao,GenerateWinnersAndFillMailingQueueJobExecutor,GenerateWinnersAndFillMailingQueueJobDetail,GenerateWinnersAndFillMailingQueueJob,SendEmailsFromMailQueueJobExecutor,SendEmailsFromMailQueueJobDetail,SendEmailsFromMailQueueJob,org.springframework.scheduling.quartz.SchedulerFactoryBean#0,org.springframework.security.web.PortMapperImpl#0,org.springframework.security.web.context.HttpSessionSecurityContextRepository#0,org.springframework.security.authentication.ProviderManager#0,org.springframework.security.access.vote.AffirmativeBased#0,org.springframework.security.web.access.intercept.FilterSecurityInterceptor#0,org.springframework.security.web.access.DefaultWebInvocationPrivilegeEvaluator#0,org.springframework.security.authentication.AnonymousAuthenticationProvider#0,org.springframework.security.web.savedrequest.HttpSessionRequestCache#0,org.springframework.security.config.http.UserDetailsServiceInjectionBeanPostProcessor#0,org.springframework.security.filterChainProxy,sessionAuthenticationStrategy,sessionRegistry,propertyConfigurer,org.springframework.security.authentication.dao.DaoAuthenticationProvider#0,org.springframework.security.authentication.DefaultAuthenticationEventPublisher#0,org.springframework.security.authenticationManager,saltSource,dataSource,jdbcTemplate,passwordEncoder,jdbcUserService,loggerListener,formLoginFilter,authenticationEntryPoint,accessDeniedHandler,concurrencyFilter]; root of factory hierarchy
2011-08-29 08:49:22,601 {ABSOLUTE}  INFO SchedulerFactoryBean,Thread-9:760 - Shutting down Quartz Scheduler
2011-08-29 08:49:22,601 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:616 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED shutting down.
2011-08-29 08:49:22,602 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:537 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED paused.
2011-08-29 08:49:22,603 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:688 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED shutdown complete.
2011-08-29 08:49:22,882 {ABSOLUTE}  INFO XmlWebApplicationContext,Thread-9:1002 - Closing Root WebApplicationContext: startup date [Sun Aug 28 20:53:34 CEST 2011]; root of context hierarchy
2011-08-29 08:49:22,883 {ABSOLUTE}  INFO DefaultLifecycleProcessor,Thread-9:345 - Stopping beans in phase 2147483647
2011-08-29 08:49:22,903 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:537 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED paused.
2011-08-29 08:49:22,904 {ABSOLUTE}  INFO DefaultListableBeanFactory,Thread-9:422 - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@402fb002: defining beans [org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,MerchantSimpleJsonWebservice,merchantDao,AdvertisementSimpleJsonWebservice,advertisementDao,ContactFormSubmitsSimpleJsonWebservice,contactFormSubmitsDao,PlayerCustomJsonWebservice,PlayerCustomJsonWebserviceImpl,submitSolutionDao,GenerateWinnersAndFillMailingQueueJobExecutor,GenerateWinnersAndFillMailingQueueJobDetail,GenerateWinnersAndFillMailingQueueJob,SendEmailsFromMailQueueJobExecutor,SendEmailsFromMailQueueJobDetail,SendEmailsFromMailQueueJob,org.springframework.scheduling.quartz.SchedulerFactoryBean#0,org.springframework.security.web.PortMapperImpl#0,org.springframework.security.web.context.HttpSessionSecurityContextRepository#0,org.springframework.security.authentication.ProviderManager#0,org.springframework.security.access.vote.AffirmativeBased#0,org.springframework.security.web.access.intercept.FilterSecurityInterceptor#0,org.springframework.security.web.access.DefaultWebInvocationPrivilegeEvaluator#0,org.springframework.security.authentication.AnonymousAuthenticationProvider#0,org.springframework.security.web.savedrequest.HttpSessionRequestCache#0,org.springframework.security.config.http.UserDetailsServiceInjectionBeanPostProcessor#0,org.springframework.security.filterChainProxy,sessionAuthenticationStrategy,sessionRegistry,propertyConfigurer,org.springframework.security.authentication.dao.DaoAuthenticationProvider#0,org.springframework.security.authentication.DefaultAuthenticationEventPublisher#0,org.springframework.security.authenticationManager,saltSource,dataSource,jdbcTemplate,passwordEncoder,jdbcUserService,loggerListener,formLoginFilter,authenticationEntryPoint,accessDeniedHandler,concurrencyFilter]; root of factory hierarchy
2011-08-29 08:49:22,913 {ABSOLUTE}  INFO SchedulerFactoryBean,Thread-9:760 - Shutting down Quartz Scheduler
2011-08-29 08:49:22,914 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:616 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED shutting down.
2011-08-29 08:49:22,914 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:537 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED paused.
2011-08-29 08:49:22,915 {ABSOLUTE}  INFO QuartzScheduler,Thread-9:688 - Scheduler org.springframework.scheduling.quartz.SchedulerFactoryBean#0_$_NON_CLUSTERED shutdown complete.
2011-08-29 08:49:26,484 {ABSOLUTE}  INFO ContextLoader,main:187 - Root WebApplicationContext: initialization started

Later on, two Spring instances seem to be started:

2011-08-29 08:49:26,484 {ABSOLUTE}  INFO ContextLoader,main:187 - Root WebApplicationContext: initialization started
...
2011-08-29 08:49:31,221 {ABSOLUTE}  INFO ContextLoader,main:187 - Root WebApplicationContext: initialization started

What can be causing this, and what's to be done?

Landgrave

It might be a good idea to increase quartz' logging level a bit to see if the job actually gets scheduled twice for execution. – Lawn

Thanks. I put the spring log level to debug, and it looks like spring runs twice (But it's the only app deployed)! Either spring runs twice, OR the quartz scheduler bean is instantiated twice. I've put the log in the question above – Landgrave

I have observed this behavior without quartz as well. The spring context was getting loaded twice whenever I ran the app on Tomcat (even on windows from within netbeans). – Arc

Answer 1

I fixed it, not only quartz was running twice, but my app was deployed twice. This was because of the following in the Tomcat docs:

When using automatic deployment, the docBase defined by an XML Context file should be outside of the appBase directory. If this is not the case, difficulties may be experienced deploying the web application or the application may be deployed twice. The deployIgnore attribute can be used to avoid this situation.

Finally, note that if you are defining contexts explicitly in server.xml, you should probably turn off automatic application deployment or specify deployIgnore carefully. Otherwise, the web applications will each be deployed twice, and that may cause problems for the applications.

I followed a tutorial on how to get mod_jk working, and this tutorial contained that flaw.

Landgrave

Answer 2

For me, the auto deployment was the problem, and to disable it I had to specify the following attributes on the host element in my server.xml:

deployOnStartup="false"
autoDeploy="false"

So my host element looked like this:

  <Host name="localhost" 
        deployOnStartup="false"  
        appBase="webapps" 
        unpackWARs="false" 
        autoDeploy="false">

I found this post detailing the problem in a different way that helped me resolve this issue.

Unwinking

Answer 3

Do you eventually have multiple applications running inside one Tomcat instance on your Ubunut machine? I think I remember Quartz to have some static code, which it would share througout all applications in one Java VM.

Dallon

Thanks for your answer. And yes, i just figured out that not only quartz was running twice, but the whole app was deployed twice. See my answer below. – Landgrave