tracker issue : CF-4086307

select a category, or use search below
(searches all categories and all time range)
Title:

Coldfusion fills up its scheduler and exception logs with invalid "Task Invokehandler could not be chained" error message

| View in Tracker

Status/Resolution/Reason: Closed/Fixed/

Reporter/Name(from Bugbase): Byron H Knapp / Byron H Knapp (Byron H Knapp)

Created: 11/10/2015

Components: Scheduler

Versions: 11.0

Failure Type: Usability Issue

Found In Build/Fixed In Build: CF11_Final /

Priority/Frequency: Normal / Unknown

Locale/System: English / Win 2003 Ent. Edition

Vote Count: 0

Listed in the version 2016.0.03.300466 Issues Fixed doc
Problem Description: Coldfusion is filling up its scheduler.log and exception.log with invalid "Task Invokehandler could not be chained" error messages.

Steps to Reproduce: see 'Test Configuration' section for my complete write-up of the problem

Actual Result: Scheduled Tasks creating many invalid 'error' lines in the logs EVERY time ANY scheduled task (that was migrated from CF9 into CF11) is run. (No errors are reported if that same task is created from scratch using CF11).

Expected Result: Scheduled Tasks should create no invalid 'error' lines in the logs.

Any Workarounds: delete all prior CF scheduled tasks and re-enter them from scratch

----------------------------- Additional Watson Details -----------------------------

Watson Bug ID:	4086307

External Customer Info:
External Company:  
External Customer Name: Byron H Knapp
External Customer Email:  
External Test Config: Hi, 

PROBLEM:

Coldfusion is filling up its scheduler.log and exception.log with invalid "Task Invokehandler could not be chained" error messages.



ADDITIONAL INFO: 

We have about 150 scheduled Coldfusion tasks that were setup in CF9. We then migrated from CF9 to CF11 (using the normal Adobe migration tools/procedures). We experienced no problems with the migration process.



All the scheduled tasks seemed to migrate OK (there is a new field on the CF11 scheduler properties screen called "chained task". It is blank.). All of these tasks run fine. 



However, there is invalid "error" information added to both the scheduler and exception logs EACH TIME one of these scheduled tasks runs. Below I have included the log snips of a sample "error". (Each error creates SIX additional lines in the exception.log!) 



Then, as a test, I add a NEW scheduled task. I make it identical to one of those converted tasks, except that the new task runs at a slightly different time.



This NEW task works fine and it does NOT log error messages. The only difference is that it was created with CF11 (instead of being created with CF9 and then migrated to CF11).



And finally, if I bring up one of those 150 tasks inside the CF Scheduled Task GUI, and then I make a minor change to its properties (like adjusting the time it runs), and then SAVE the properties screen, the problem does NOT go away (in case you are wondering, as I did, if that would fix it). 



Any ideas how I can fix my scheduled tasks from filling up my logs, so I don't have to delete, and then re-enter 150 tasks?

Thanks!

Byron_K

-----------------



LOG SNIP for SCHEDULER.log



"Information","DefaultQuartzScheduler_Worker-6","11/10/15","17:51:02",,"Task DEFAULT.My-Task"

"Error","DefaultQuartzScheduler_Worker-6","11/10/15","17:51:02",,"Task invokehandler could not be chained"

. . . . . . . . . . . . . . . . . . . . . . . . .



LOG SNIP for EXCEPTION.log



"Error","DefaultQuartzScheduler_Worker-6","11/10/15","17:51:02",,"Task DEFAULT.My-Task"

java.lang.Exception: Task invokehandler could not be chained

	at coldfusion.scheduling.CronTask.onCompleteTask(CronTask.java:215)

	at coldfusion.scheduling.CronTask.execute(CronTask.java:130)

	at org.quartz.core.JobRunShell.run(JobRunShell.java:207)

	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:560)

Attachments:

Comments:

Hi Byron, I tried to repro your case but was unsuccessful. I tried the following steps: 1.Created 150 tasks in CF9 using this simple script: <cfloop index = "i" from = "1" to = "150"> <cfschedule action="update" task="t1_#i#" operation="HTTPRequest" startdate="#now()#" starttime="#now()#" interval="daily" URL="www.google.com"> </cfloop> 2. Migrated these tasks using ColdFusionArchives to CF11. 3. Ran one of this task from CF11 Admin. 4. Did not see any error entry in the log. Can you send us your neo-cron.xml file so that we can look at the tasks you have created? Also,any info from your side that could help us to repro the bug. Thanks & Regards, Suchika.
Comment by Suchika S.
5365 | December 04, 2015 05:58:40 AM GMT
Hi Suchika, your timing is perfect since in the time since I posted this bug, I have tracked down the cause and found the "work-around". Since the problem was created DURING the CF9 to CF11 migration, once the work-around (below) is applied, the problem should not happen again. ANALYSIS: The PROBLEM is that a VALUE was added to a NEW field in CF11's NEO-CRON.xml when our CF9 was migrated to CF11 (using the Adobe migration tools). This field is called 'oncomplete' and it does not exist in CF9. However, when migrating to CF11, that field is being set to "invokehandler" (found in the scheduled item GUI's "show additional settings" property page - which I had missed earlier). That "oncomplete" = "invokehandler" setting in the NEO-CRON.xml is what is causing the logging errors (that I already reported). {{from the NEO-CROM.xml: <var name='oncomplete'><string>invokehandler</string></var> }} (BTW, the CF9 to CF11 migration added this OnComplete=invokehandler to every single scheduled task during the CF9 to CF11 migration.) IF I delete the CF11 scheduled item and set it up again from scratch, CF11 will set "oncomplete" to NULL and then the problem goes away. {{from the NEO-CROM.xml: <var name='oncomplete'><string></string></var> }} WORKAROUND: after the CF9 to CF11 migration (but before you make any changes to your newly migrated scheduled items), go in to the CF scheduler GUI and set 'On Complete' to NULL on all scheduled items. Alternative method: with CF stopped, use a text editor and search/replace all occurrences of invokehandler to null in the NEO-CRON.xml file. QUESTIONS left hanging: WHAT is invokehandler and WHY is it being added to the new 'On Complete' field when CF9 is migrated to CF11, and WHY does this not happen to you in your testing? Byron ps: I did my migration from CF9 to CF11 while on W2K3. I am unable to tell you if Adobe's CF9 to CF11 migration tool causes this bug when upgrading CF9 to CF11 while on W2K12. However, I migrated from W2K3 to W2K12 after the CF9 to CF11 migration, and NEO-CRON.xml's "oncomplete=invokehandler" DID cause the logging errors exactly the same on W2K3 and W2K12.
Comment by External U.
5366 | December 04, 2015 06:21:51 PM GMT
Hi Suchika, Sounds like migration wizard is populating an incorrect value for oncomplete in neo-cron.xml. It should only be "invokehandler" if an event handler was specified - which, of course, isn't the case when the tasks were created in CF9. Thanks!, -Aaron
Comment by External U.
5367 | December 05, 2015 05:49:32 AM GMT
Hi Byron, I checked my neo-cron.xml and found the following value for onComplete: <var name="onComplete"><null/></var>,which is incorrect. Although I find error lines in the log, on executing the task. Nevertheless, value populated is incorrect hence marking the bug as ToFix. Thanks, Suchika.
Comment by Suchika S.
5368 | December 10, 2015 02:59:49 AM GMT
Very odd. How then does the word "invokehandler" get put into all of MY "oncomplete" fields during migration then? Sounds like you can't get your migration to do that... odd. Perhaps the migration tool has been upgraded since I used it a year ago then?
Comment by External U.
5369 | December 10, 2015 10:10:47 AM GMT