I have ThreadPoolTaskScheduler scheduled by CronTrigger and observe quite strange thing. I run a simple task in it, that just prints the current date and time. Like that:
public class MyCron {
Logger logger = LoggerFactory.getLogger(MyCron);
private final ThreadPoolTaskScheduler scheduler;
private final CronTrigger cronTrigger;
private ScheduledFuture<?> runnableTask;
public MyCron(String cronEntry) {
this.scheduler = new ThreadPoolTaskScheduler();
this.scheduler.setPoolSize(10);
this.scheduler.setThreadNamePrefix("MyCron-" + name + "-");
this.scheduler.initialize();
this.cronTrigger = new CronTrigger(cronEntry);
runnableTask = scheduler.schedule(this::workerThread, cronTrigger);
}
where this::workerThread prints a date and time. But I observe it runs a little bit earlier that scheduled, like for the cron strings 0 */5 * * * * and 0 */7 * * * * I observe the following:
mycron | 2024-05-30T17:59:59.844Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 17:59:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:04:59.785Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:04:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:06:59.702Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:06:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:09:59.785Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:09:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:13:59.702Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:13:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:14:59.784Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:14:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:19:59.785Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:19:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:20:59.665Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:20:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:24:59.746Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:24:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:27:59.692Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:27:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:29:59.783Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:29:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:34:59.694Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:34:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:34:59.783Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:34:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:39:59.782Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:39:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:41:59.694Z INFO 1 --- [n-Cron test 2-7] c.e : Cron test 2 worker is running: Thu May 30 2024 18:41:59 GMT+0000 (UTC)
mycron | 2024-05-30T18:44:59.790Z INFO 1 --- [n-Cron test 1-1] c.e : Cron test 1 worker is running: Thu May 30 2024 18:44:59 GMT+0000 (UTC)
I don't understand how is it possible and why could this happen. Am I doing something wrong?
My versions are: Running with Spring Boot v3.3.0, Spring v6.1.8
Thank you!
Update: I see a close request because question is unclear. I supposed it's pretty clear but I'll try to explain it further anyways. As I specified CronTrigger's seconds set to zero, I expect my scheduler will run at zero seconds, not on 59th second. This is the least. Another side is, that if I set it to run on every 5th minute, I expect it to run on 18:05:00, not on 18:04:59. Here's the link to javadoc: https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/scheduling/support/CronExpression.html#parse(java.lang.String)
Update/explanation - why is it important:
In my task, i run a sql query with where condition like where timestamp < current_timestamp() As it runs within container, it performs really fast and condition is not triggering. Quite strange, is it such a rare case?
Well, according to the issue 29735, they consider it's not a bug. So, I added the code like that to the task as a workaround
long now = System.currentTimeMillis();
long fraction = now - now / 1000 * 1000;
if (fraction > 500) {
TimeUnit.MILLISECONDS.sleep(1000L - fraction);
}
A bit too ugly and smelling, but I see no other solutions as they don't want to fix it.