High CPU usage - due to scheduled tasks

TonyMonast · February 16, 2021, 7:39pm

I tried to find a pattern for the bug. It’s directly related to the scheduled task interval :

10000 (2,777778 hours) ok
10400 (2,8888889 hours) ok
10800 (3 hours) bug
10810 (3,0027778 hours) ok
14400 (4 hours) bug
14700 (4,0833333 hours) ok
18000 (5 hours) ok

At first I thought it was coming from a rounding issue and/or data type (int vs float), because it was buggy just with whole number like 3 and 4 hours, but it’s okay with 5 hours. It’s strange.

For now I just changed the interval 14400 to 14700 for my problematics scheduled tasks and the Lucee CPU dropped at 0%.

I wonder if it’s specific to our server configuration or if anybody who use an interval of 14400 will have this issue…

If I can help in anyway to solve this issue, let me know!

Zackster · February 16, 2021, 7:47pm

I think it’s maybe something to do with this while(true) loop in revertDST

the code is slightly different in 5.3 as it includes a fix for this issue with DST

github.com

lucee/Lucee/blob/5.3/core/src/main/java/lucee/runtime/schedule/ScheduledTaskThread.java#L464


      
          			}
          		}
          		// print.e("next2:" + new Date(next));
          		return next;
          	}
          
          
	private static void revertDST(Calendar c, int hourExpected, int intervall, int amount) {
          		int hour = c.get(Calendar.HOUR_OF_DAY);
          		if (hour == hourExpected) return;
          		// go back until it shifts
          		while (true) {
          			// print.e("- " + c.getTime());
          			c.add(intervall, -amount);
          			hour = c.get(Calendar.HOUR_OF_DAY);
          			if (hour <= hourExpected) {
          				c.add(intervall, amount);
          				break;
          			}
          		}
          	}

github.com

lucee/Lucee/blob/5.3.7.47/core/src/main/java/lucee/runtime/schedule/ScheduledTaskThread.java#L422


      
          		c.setTimeInMillis(now);
          		c.set(Calendar.HOUR_OF_DAY, 0);
          		c.set(Calendar.MINUTE, 0);
          		c.set(Calendar.SECOND, 0);
          		c.set(Calendar.MILLISECOND, 0);
          		c.setTimeInMillis(c.getTimeInMillis() + endTime);
          		long end = c.getTimeInMillis();
          
          
		c.setTimeInMillis(now);
          		c.set(Calendar.HOUR_OF_DAY, startHour);
          		revertDST(c, Calendar.HOUR_OF_DAY, startHour, Calendar.SECOND, amount);
          		c.set(Calendar.MINUTE, startMinute);
          		c.set(Calendar.SECOND, startSecond);
          		c.set(Calendar.MILLISECOND, startMilliSecond);
          		long next = c.getTimeInMillis();
          
          
		// is it already in the future or we want not now
          		while (next <= now) {
          			// we allow now
          			if (!notNow) {
          				long diff = now - next;

TonyMonast · February 16, 2021, 8:07pm

It makes sense.

Note that if my scheduled task use an interval of 14400 and start at {t ‘06:00:00’}, it’s fine. But if it’s start at 00:00:00, or 00:30:00, or 01:00:00 the bug still occur. This is indeed a bug depending on the combination of start time and interval, and maybe end time as well.

Zackster · February 16, 2021, 9:48pm

good detective work, can you post your findings in the task

TonyMonast · February 17, 2021, 1:08pm

I posted my findings in the bug report [LDEV-3214] - Lucee.

Zackster · March 8, 2021, 10:39pm

this was addressed in 5.3.8.156, please try it out (when the build finishes)

kpetrow · March 9, 2021, 2:43pm

I too also had scheduled tasks high cpu when converting from railo to lucee. I binnary searched around 250 tasks and found 5 offenders. No rhyme or reason to what they were

TonyMonast · March 16, 2021, 5:17pm

Hi @Zackster,

I don’t see the version 5.3.8.156 in the Update section of the server admin. Is it normal?

I suppose the version 5.3.8.159-SNAPSHOT should be fine too? I tried the version 5.3.8.159-SNAPSHOT with my old scheduled tasks settings and everything look normal in the CPU usage.

Thank you!

harryf · October 31, 2021, 11:58am

I had the same problem and by turning off Debugging*, everything was fine again.

I turned on Debugging to use the fantastic Performance Analyzer plugin.