Bug: Duplicate Scheduled Tasks after Lucee Engine Restart

Juan_Aguilar · February 1, 2019, 2:43pm

We had an issue yesterday where our scheduled tasks started running twice at the same time.

Our logs show this began to happen after we restarted the engine from within the Lucee Server Admin.

127.0.0.1 - - [31/Jan/2019:12:56:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:12:58:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:00:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:02:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
192.168.1.147 - - [31/Jan/2019:13:03:28 -0500] "GET /lucee/admin/server.cfm HTTP/1.1" 200 1243 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:28 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:28 -0500] "GET /lucee/form.cfm HTTP/1.1" 200 4175 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/js/jquery.blockUI-3e22a90fcc64a9e6.js.cfm HTTP/1.1" 200 6703 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/js/admin-3e22a90fcc64a9e6.js.cfm HTTP/1.1" 200 3003 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/js/util-3e22a90fcc64a9e6.min.js.cfm HTTP/1.1" 200 1169 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/img/admin_sprite.png.cfm HTTP/1.1" 200 15195 "https://admin.internal.local:8443/lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/js/jquery-1.12.4.min.js.cfm HTTP/1.1" 200 34283 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:29 -0500] "GET /lucee/res/img/bg_server.gif.cfm HTTP/1.1" 200 113857 "https://admin.internal.local:8443/lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:32 -0500] "POST /lucee/admin/server.cfm HTTP/1.1" 302 96 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:32 -0500] "GET /lucee/admin/server.cfm?action=services.restart HTTP/1.1" 200 2179 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:32 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:33 -0500] "GET /favicon.ico HTTP/1.1" 200 1150 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:35 -0500] "GET /lucee/res/img/spinner16.gif.cfm HTTP/1.1" 200 1849 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:03:46 -0500] "GET /lucee/admin/restart.cfm?CFID=9ad4deab-b0f9-445c-8efc-4f355441888c&CFTOKEN=0&adminType=server HTTP/1.1" 200 1 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:06 -0500] "GET /lucee/admin/server.cfm HTTP/1.1" 200 1239 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:06 -0500] "GET /lucee/form.cfm HTTP/1.1" 200 4175 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:06 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:11 -0500] "POST /lucee/admin/server.cfm HTTP/1.1" 302 96 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:11 -0500] "GET /lucee/admin/server.cfm?action=services.restart HTTP/1.1" 200 2179 "https://admin.internal.local:8443/lucee/admin/server.cfm" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:11 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:13 -0500] "GET /lucee/admin/server.cfm?action=overview HTTP/1.1" 200 3860 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.restart" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:13 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=overview" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:13 -0500] "GET /lucee/res/img/spinner16.gif.cfm HTTP/1.1" 200 1849 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=overview" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:13 -0500] "GET /lucee/form.cfm HTTP/1.1" 200 4175 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=overview" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:17 -0500] "GET /lucee/admin/update.cfm?CFID=9ad4deab-b0f9-445c-8efc-4f355441888c&CFTOKEN=0&adminType=server HTTP/1.1" 200 1205 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=overview" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:21 -0500] "GET /lucee/admin/server.cfm?action=services.update HTTP/1.1" 200 3560 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=overview" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:21 -0500] "GET /lucee/form.cfm HTTP/1.1" 200 4175 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.update" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
192.168.1.147 - - [31/Jan/2019:13:04:21 -0500] "GET /lucee/res/css/admin-3e22a90fcc64a9e6.css.cfm HTTP/1.1" 200 6188 "https://admin.internal.local:8443/lucee/admin/server.cfm?action=services.update" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_0) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36"
127.0.0.1 - - [31/Jan/2019:13:06:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:06:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:08:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:08:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:10:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"
127.0.0.1 - - [31/Jan/2019:13:10:00 -0500] "GET /scheduled/tasks.cfc?method=processTask1&RequestTimeout=600 HTTP/1.1" 200 389 "-" "CFSCHEDULE"

If you’ve have duplicate scheduled tasks, this might be the reason why!

Zackster · February 1, 2019, 4:57pm

which version of lucee?

Juan_Aguilar · February 1, 2019, 5:21pm


Lucee Version	5.2.7.63
OS	Linux (4.4.0-1074-aws) 64bit
Servlet Container	Apache Tomcat/8.5.23
Java	1.8.0_144 (Oracle Corporation) 64bit

August_Kleimo · February 4, 2019, 10:04pm

I’m also experiencing this issue on:

Lucee Version 5.2.9.31
Linux (4.9.43-17.39.amzn1.x86_64) 64bit
Apache Tomcat/8.5.16
1.8.0_144 (Oracle Corporation) 64bit

David_Raschper · February 5, 2019, 8:12am

Does it still exist when you do a full restart (with tomcat) ?

lutz · February 5, 2019, 10:10am

Might be the same issue discussed a few months ago here:
https://lucee.daemonite.io/t/duplicate-scheduled-tasks/4086

Cliff_Mosdall · February 8, 2019, 9:24am

I had the same issue. Only fix was to delete all the tasks and insert them again. It occurs after every Lucee update.

viks120 · May 13, 2019, 6:49pm

Hello,

I am having same issues. Deleted scheduled task but Lucee still try to run it. I can see in the log.

I had to rename the file.

Lucee Version: 5.2.9.31

Please fix it.

bdw429s · May 13, 2019, 9:35pm

@viks120 This forum is a great place to chat with other CF developers about your Lucee questions. However, the Lucee developer team does not frequent this forum, so declaring “please fix it” isn’t going to get you anywhere If you have a bug, please enter a ticket. if there is already a ticket in place, please vote on it and provide any additional information you can.

Zackster · May 13, 2019, 10:34pm

Please file a new bug, but before doing that, please test the latest snapshot to see if it’s been already fixed, 5.2.9.31 is old.

purdue512 · August 9, 2020, 11:38am

Thanks Zac. We hit this duplicate scheduled task issue ourselves on Friday in 5.2.8.50. This was after we hit the issue on 5.3.6.61 related to cf_client_data clean-up, and then failed our servers back to an earlier image of 5.2.8.50. I have logs of this happening I can share.

As you recommended, we have been trying to move up to the lastest version - but are hitting severe performance issues as discussed here:

https://lucee.daemonite.io/t/regression-cf-client-data-not-deleting-in-5-3-6-61/7293

However - I can’t really get a response on the issue.

Zackster · August 9, 2020, 12:52pm

But have you filed a bug?

purdue512 · August 9, 2020, 1:15pm

Hi Zac! Thanks so much for your response.

I have not. I had thought I read the better approach was to post it here with “REGRESSION” so that others could advise first… If it’s better to file a bug - happy to do that.

Would you mind dropping the link for a new bug here? I read the documentation, but I think the links are old.

Also - stupid question on my part probably - but by “bug” do you mean “issue”? Again - Want to do what is most helpful.