Scheduler doesn't trigger the Job on time

[rahuchats]

Hi Team,

I am using org.quartz-scheduler.quartz version 2.2.3 in a springboot project. We have handful of jobs to run through the scheduler. I am using MySQL DB to fetch data. Let me try to explain the scenario

• In my local system , there are absolutely no issues with job being triggered on time. I am using local MySQL DB for that. The jobhistory table shows the information of job time start and end. It's perfectly in the duration I am expecting. I can trigger the jobs within 1 or 2 mins interval and since the data is not huge, my job triggers and completes on time.

The issue is happening in next level environment i.e. Development. I am expecting the job to take same amount of time provided with same set of DB data , but it doesn't complete as expected.

I scheduled only 1 job and scheduling the job with 2 mins interval. The first trigger kicks off at correct time. For second trigger ,when I see the Quartz trigger table, it shows status as BLOCKED. This possible because the first one didn't complete. I am using threadpool=5 . It waits for almost 40 mins to complete the first trigger , that is when the jobhistory gets updated with start and end time. So, starttime=5 pm and end at 5:40 pm. So, I decided to put job trigger in 60 mins interval. Now, I am having the job completing in random interval of 40mins or sometime 35 mins or sometime 29 mins etc. So, I could see my job got triggered on time evry one hour but still taking ~40 mins. My custom code business logic takes only 2 seconds to complete.

[DEBUG] [2020-06-30 20:58:11.249] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 20:58:41.741] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 20:59:09.784] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 20:59:39.079] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 1 triggers
[DEBUG] [2020-06-30 21:00:00.063] [org.quartz.impl.jdbcjobstore.StdRowLockSemaphore] [obtainLock:107] - Lock 'TRIGGER_ACCESS' is desired by: idm-scheduler_QuartzSchedulerThread
[DEBUG] [2020-06-30 21:00:00.559] [org.quartz.impl.jdbcjobstore.StdRowLockSemaphore] [executeSQL:92] - Lock 'TRIGGER_ACCESS' is being obtained: idm-scheduler_QuartzSchedulerThread
[DEBUG] [2020-06-30 21:00:01.056] [org.quartz.impl.jdbcjobstore.StdRowLockSemaphore] [obtainLock:116] - Lock 'TRIGGER_ACCESS' given to: idm-scheduler_QuartzSchedulerThread
[DEBUG] [2020-06-30 21:00:01.625] [org.quartz.impl.jdbcjobstore.StdRowLockSemaphore] [releaseLock:141] - Lock 'TRIGGER_ACCESS' returned by: idm-scheduler_QuartzSchedulerThread
[DEBUG] [2020-06-30 21:00:02.146] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 21:00:28.224] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers

---- same statements of batch acquisition of 0 triggers being logged -----------------

[DEBUG] [2020-06-30 21:24:18.457] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 21:24:46.540] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 21:25:14.557] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 0 triggers
[DEBUG] [2020-06-30 21:25:37.666] [gov.hhs.cms.idm.scheduler.events.EventsListener] [triggerFired:138] - Trigger Fired:

-- custom code getting executed and completed in 2 seconds max ----------------

I see the statement ([DEBUG] [2020-06-30 20:59:39.079] [org.quartz.core.QuartzSchedulerThread] [run:276] - batch acquisition of 1 triggers) tried to acquire the trigger at the correct time but didn't execute the logic until 25 minutes are passed.

What is quartz trying to do in those 25 mins ? How can I debug this situation in Dev environment ? I already added logging for org.quartz package but I don't see any useful information. Could someone suggest any direction on what can be done here ? I am kind of stuck.

Note: The same code is taking 6 to 13 mins in another higher environment. So, it's not as bad as Dev environment but still not convincing to rely on such performance. It should be consistent so that I can predict the performance.

[Imjiajiawang]

I have the same problem with use in postgres 11. Quartz always lost my job but triggers be update.

[Imjiajiawang]

Does it have to do with thread level?

[Imjiajiawang]

Can you tell me how to start the Quartz log？

[rahuchats]

Can you tell me how to start the Quartz log？

I am not sure if I understand your question correctly. If you are looking for quartz package logs, you will have to add a logger statement in your log4j or logback xml, whichever logging mechanism you are using. Something like this :

[Imjiajiawang]

Can you tell me how to start the Quartz log？

I am not sure if I understand your question correctly. If you are looking for quartz package logs, you will have to add a logger statement in your log4j or logback xml, whichever logging mechanism you are using. Something like this :

I got it.Thank you for reminding me.

[manjush]

As the status for trigger table is in BLOCKED State
Maybe good to update the Quartz to 2.3.1
Please go through this issue
#145

[stale]

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.