我们有一个基于石英的调度程序应用程序,它每分钟运行大约 1000 个作业,这些作业均匀分布在每分钟的几秒钟内,即每秒大约 16-17 个作业。理想情况下,这 16-17 个作业应该同时触发,但是我们的第一条语句(它只是记录执行时间)的执行方法被调用得很晚。例如,假设我们从 05:00 到 05:04 每分钟安排了 1000 个作业。因此,理想情况下,安排在 05:03:50 的作业应该在 05:03:50 记录执行方法的第一条语句,但是,它是在大约 05:06:38 执行的。我已经追踪了大约 15-20 毫秒的预定作业所花费的时间。这个计划作业足够快,因为我们只是在 ActiveMQ 队列上发送消息。我们已将石英的线程数指定为 100,甚至尝试将其增加到 200 或更多,但没有任何收获。我们注意到的另一件事是调度程序的日志在前 1 分钟后是连续的,即
[Quartz_Worker_28] <Some log statement>
..
..
[Quartz_Worker_29] <Some log statement>
..
..
[Quartz_Worker_30] <Some log statement>
..
..
所以它表明在一段时间后,石英运行线程几乎是连续的。这可能是由于将作业完成通知到持久性存储(在这种情况下是一个单独的 postgres 数据库)和/或上下文切换所花费的时间。
这种奇怪行为背后的原因是什么?
编辑:更详细的日志
[06/07/12 10:08:37:192][QuartzScheduler_Worker-34][INFO] org.quartz.plugins.history.LoggingTriggerHistoryPlugin - Trigger [<trigger_name>] fired job [<job_name>] scheduled at: 06-07-2012 10:08:33.458, next scheduled at: 06-07-2012 10:34:53.000
[06/07/12 10:08:37:192][QuartzScheduler_Worker-34][INFO] <my_package>.scheduler.quartz.ScheduledLocateJob - execute begin--------- ScheduledLocateJob with key: <job_name> started at Fri Jul 06 10:08:37 EDT 2012
[06/07/12 10:08:37:192][QuartzScheduler_Worker-34][INFO] <my_package>.scheduler.quartz.ScheduledLocateJob <some log statement>
[06/07/12 10:08:37:192][QuartzScheduler_Worker-34][INFO] <my_package>.scheduler.quartz.ScheduledLocateJob <some log statement>
[06/07/12 10:08:37:192][QuartzScheduler_Worker-34][INFO] <my_package>.scheduler.quartz.ScheduledLocateJob <some log statement>
[06/07/12 10:08:37:220][QuartzScheduler_Worker-34][INFO] <my_package>.scheduler.quartz.ScheduledLocateJob - execute end--------- ScheduledLocateJob with key: <job_name> ended at Fri Jul 06 10:08:37 EDT 2012
[06/07/12 10:08:37:220][QuartzScheduler_Worker-34][INFO] org.quartz.plugins.history.LoggingTriggerHistoryPlugin - Trigger [<trigger_name>] completed firing job [<job_name>] with resulting trigger instruction code: DO NOTHING. Next scheduled at: 06-07-2012 10:34:53.000
我对上述日志的这一部分表示怀疑
scheduled at: 06-07-2012 10:08:33.458, next scheduled at: 06-07-2012 10:34:53.000
因为这项工作计划在 10:04:53 进行,但它在 10:08:33 触发,但石英仍然不认为它是失败的。不应该是失火吗?