Bug: Duplicate Scheduled Tasks after Lucee Engine Restart


#1

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!


#2

which version of lucee?


#3
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

#4

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


#5

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


#6

Hi @Juan_Aguilar, @August_Kleimo,

If possible can you share your test file. It’ll more helpful to reproduce the issue.


#7

Might be the same issue discussed a few months ago here:


#8

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