Strange Scheduled Task (Quartz) behaviour CF10

Report · Oct 28, 2013

Hi,

I'm running ColdFusion 10 Enterprise on a RHEL 6 server and have come across an intersting behaviour in relation to the scheduled tasks we have setup.

We noticed that after a reboot of our ColdFusion server that the scheduled tasks weren't running correctly.

When I looked in the http.log file I could see that it was trying to execute the correct template

"Information","DefaultQuartzScheduler_Worker-9","10/25/13","07:18:16",,"Starting HTTP request {URL='...', method='get'}"

But the request never appears to be completed. When a task successfully runs you would expect to see a completed line as well in the http.log file

"Information","DefaultQuartzScheduler_Worker-9","10/25/13","07:18:21",,"HTTP request completed {Status Code=200 ,Time taken=4896 ms}"

For some reason after the server reboot the task is triggered, but it never runs and never shows as being complete.

I was playing changing settings in the scheduled task and checked the Save output to a file check box. As soon as I did that and put in a valid path the scheduled task started to run and complete. If I uncheck output to a file the task will continue to run until the ColdFusion server is restarted. As soon as the server restarts it reverts back to not running. However if I leave the output to a file option checked and restart the CF server the task runs and completes as expected!

One other thing I noticed was that the catalina task (check for update/hotfix) would execute and return while the other tasks (quartz) wouldn't.

Has anyone seen anything similar or have any suggestions? For now i'll just make sure my tasks all output to a file, but if there was a way to fix it I would much prefer to do that.

Thanks

Simon

Report · Oct 29, 2013

Hi

I have seen something very similar to this. However, in my case the reason seems to be that CF10 does not obey HTTP proxy commands via jvm.config. You have to specifically set your proxy server for every scheduled task.

Also, I noticed that the scheduled tasks screen will not work correctly in CFIDE if you access it from an external IP address, even if you enable that IP address to have CFAdmin access.

Report · Oct 31, 2013

Hi Pat

I had a similar problem with tasks needing the proxy address and port added to them.

Out of interest what were the arguments you tried in the jvm config for the proxy?

Cheers,

Simon

Report · Nov 03, 2013

I tried lots of combos

-DproxySet=true - from all reports this does nothing

-Dhttp.proxyHost=xxx.xx.xx.xxx

-Dhttp.proxyPort=xxx

-Dhttp.proxyUsername=

-Dhttp.proxyPassword=

from what I can tell CF10 does not honor these values when CF8/9 did.

If you specify a proxy via CFHTTP or CFSCHEDULE they work, but you must do it in your code, not at JVM.config level.

I have it logged as bug

https://bugbase.adobe.com/index.cfm?event=bug&id=3647133

Report · Dec 22, 2013

I have finally had some time to do some more testing on this issue and it looks to me to somehow be related to tasks that have to use a proxy server.

I setup the same task on our development and test environments (not behind a proxy server) and after restarting the ColdFusion instance the scheduled tasks would continue to be triggered and complete successfully.

To try and confirm that the proxy is somehow involved I setup a new scheduled task that calls the same template on the server, but used it's local intranet domain so that it wouldn't need to use the proxy server.

The two tasks I have (with fake URLs)

1. Task-local (http://cf-prd/app/schedule/run.cfm)

2. Task-internet (http://www.cfapps.com/app/schedule/run.cfm) using proxy server

After restarting the ColdFusion instance the task-internet scheduled task stopped working as has previously been the case. However, Task-local using the local intranet domain continued to complete successfully.

So i'm trying to work out why needing a proxy server would be causing tasks to not complete. If I open the task in the CF admin and then click the submit button (without making a change) the task starts to complete straight away.

Can anyone think of what the cause of this might be? Or a way that I can dig a little deeper?

Cheers,

Simon

Report · Dec 23, 2013

So Simon, it would seem more diagnostics would be in order. I’ll assume you’ve been looking in the cf logs (especially application.log or exception.log) and are finding nothing untoward there. The next thing one might propose with a failing scheduled task would be to log its output, but you said in your first note that if you DID check the option to save output of the task, it would then work (and if you did NOT save it, then that’s when it did NOT work), which is indeed odd (and would seem diagnostically significant, but I don’t see a connection yet).

But what about the option to log scheduled tasks? Have you enabled that? It’s in the Debugging and Logging>Logging Settings page, and may be more helpful than looking solely at the cfhttp log (though not necessarily much better).

But speaking of that, you say that you find that when things go amiss, it’s that the task starts but never finishes, at least per the cfhttp log. That would make it seem that the request is hung up. So you would want to have a CF tool to monitor the request and perhaps even get a stack trace while it’s running to see what exactly it’s hung up doing.

In that case, are you on CF Enterprise? If so, if you open the CF Server Monitor, then turn on “Start Monitoring”, then kick off the request, you should see the task running in its Statistics>Request Statistics>Active Requests page. That would at least confirm that yes, it is stuck “running”. To get the stack trace, you either need to turn on “start profiling” and then double-click the request while it’s running, and it will show a subset of the stack trace on the next page, or even without using “start profiling” you can get the stack trace for a request within the thread dump displayed if you take a snapshot (see the snapshot tab at the top of the monitor). All that said, I realize that reading thread dumps and stack traces is not for everyone. I share more in a blog entry and talk I did, discussed here:

http://www.carehart.org/blog/client/index.cfm/2009/6/24/easier_thread_dumps

And there I also talk about using tools like FusionReactor or SeeFusion, which can also a) let you see what requests are running and b) give you a stack trace or thread dump.

If the request (for the schedule task) is indeed running and stuck on something, a stack trace if the way to see exactly what it’s doing. While resolving problems like this over email/forums can be tough, you can share at least the first several lines of a stack trace and we may be able to help offer thoughts. If it all seems too much to take in, there are folks (like myself) who can help do this via remote support, and it may take just several minutes to get to the bottom of things. I list such consultants as a category of my CF411 site, cf411.com/cfconsult.

Hope that’s helpful.

/charlie

/Charlie (troubleshooter, carehart. org)

Report · Dec 23, 2013

Hi Charlie,

Thanks for posting your thoughts, especially so close to Christmas, it is much appreciated.

I think my original observation about logging the output might be misleading. Originally when I discovered the tasks were not running correctly I checked the save output option and entered a log file to see if I could get some more information about what might be going on. When it started working I incorrectly assumed that that was the difference between tasks that worked and those that didn't. Later even the tasks that were set up to output to a log file would stop working after the CF instance was restarted. I think it was just a coincidence that lead me to that conclusion, because now if I just open the task and resave it (without any change) it starts to run successfully. The one thing that all tasks that fail have in common is the use of our proxy server.

I have had the log scheduled tasks option checked for the entire time I have been having the issue. Here is an idea of what the various coldfusion log files have logged when the task is NOT working:

1. application.log - Has no entries for the time the scheduled task is triggered

2. exception.log - Has no entries for the time the scheduled task is triggered

3. coldfusion-out.log

Dec 24, 2013 11:09:37 AM Information [DefaultQuartzScheduler_Worker-10] - Task default.TESTTASK triggered.

Dec 24, 2013 11:09:37 AM Information [DefaultQuartzScheduler_Worker-10] - Starting HTTP request {URL='...', method='get'}

4. http.log

"Information","DefaultQuartzScheduler_Worker-10","12/24/13","11:09:37",,"Starting HTTP request {URL='...', method='get'}"

5. coldfusion-error.log - Has no entries for the time the scheduled task is triggered

6. scheduler.log

"Information","catalina-exec-13","12/24/13","11:09:37",,"[TESTTASK] Executing because of user request at Tue Dec 24 11:09:37 EST 2013"

"Information","DefaultQuartzScheduler_Worker-10","12/24/13","11:09:37",,"Task default.TESTTASK triggered."

7. task's saved output file - "Connection Timeout"

Perhaps the smoking gun might be the task's saved output. I checked this morning and I get a "Connection Timeout"

We are running CF10 Enterprise and I also have FusionReactor v5 installed to monitor the instances. With FusionReactor open and monitoring the requests I don't ever see the request in the history (I'm watching all three clustered CF instances because we have round robin set up). When I trigger the task manually I can see the /CFIDE/administrator/scheduler/scheduletasks.cfm?runtask request fire and complete, but the url that the task is supposed to execute does not show up in the requests. I also don't see anything while tailing the httpd access log I have setup for CF requests, so I don't think the request is ever getting to the web server.

Based on what I see in FusionReactor and the "connection timeout" in the task's saved output, it would suggest that the request from CF/Tomcat/quartz is where the problem lies. Is there any way to inspect what quartz has stored in memory? Just saving the task fixes the issue, so perhaps there is something wrong with the job stored in memory when it is loaded from the neo-cron.xml file when the server first starts up and the act of saving it rights whatever is wrong?

I've raised a bug with Adobe in case they can shed some light on the problem

https://bugbase.adobe.com/index.cfm?event=bug&id=3687315

Cheers,

Simon

Report · Dec 23, 2013

I had a look at the neo-cron.xml file and it looks fine. The proxy_server and http_proxy_port variables are correct, so it's not a corrupt file causing issues when quartz loads the jobs on startup.

Report · Dec 23, 2013

Interesting, Simon.

So do you really mean that simply “saving” the task causes it to start running? Or do you mean that you can save it and THEN execute it, whereas if you try to execute it before doing an edit/save, it fails to run when you manually try to execute it? I don’t see how saving an edit of a task would start it running.

And are you also saying that when you save it that way that then the task will run at whatever date/time it’s scheduled? At least as long as there is not a restart of CF?

As for your observation that it could be related to the save, and a potential change in the file, I saw your subsequent note saying that the neo-cron.xml file “looks fine”, but how about saving a copy of the file after a restart, then make a change, and then compare the file. Maybe there is something you’re not seeing that does differ. That said, comparing neo xml files is tough because they are WDDX-format XML which has no order within elements, let alone between them.

The connection timeout is indeed interesting, and that along with the request never showing up in FR or the access log does indeed seem to suggest it’s never really being executed. That said, I’d still propose you may want to look at the request that tries to run the scheduled task to see when it runs how long it takes, which may give a clue. And again, you may want to stack trace the request while it’s hanging. I assume you’ll see it doing a CFHTTP (to kick off the URL defined in the task), but it would be good to confirm.

It all may also give you more info to report in the bug report you say you filed. Hope that helps.

/charlie

/Charlie (troubleshooter, carehart. org)

Report · Dec 23, 2013

Hi Charlie,

Yes it's very strange behaviour.

If the task is running successfully and the cf instance is restarted the task stops executing.

After the instance has restarted the task won't execute on either it's schedule, or a manual execution via the admin -> scheduled tasks page. Once I have "resaved" the task it automatically starts working on it's schedule (without being executed manually a first time) and will execute successfully if I manually run it.

From that point onwards the task continues to execute on it's schedule until the next time the CF instance is restarted. Which I assume is when the neo-cron.xml file is next read into memory.

I just did what you suggested and compared a non working and working neo-cron.xml files and there are some differences!

NOT WORKING neo-cron.xml WORKING neo-cron.xml

1. <var name="serverscheduletask#$%^default#$%^TESTTASK"> VS <var name="SERVERSCHEDULETASK#$%^DEFAULT#$%^TESTTASK">

2. No clustered node <var name="clustered">

<string>false</string>

</var>

3. <var name="overwrite"> <var name="overwrite">

</var> </var>

4. <var name="disabled"> No disabled node

</var>

5. <var name="eventhandlerrp"> No eventhandlerrp node

</var>

I restarted the instance while the task was working and confirmed that the not working changes were made to the cron file. Then saved the task in the cf admin and check the working changes were made to the file. Finally just for good measure I restarted the instance once again and the not working changes were back in the cron file.

The difficult thing is I can't edit the file before starting the instance because it just overwrites what's in there.

Cheers,

Simon

Report · Jan 15, 2014

Hi,

We had an application release last night which required the ColdFusion instance to be restarted. As soon as the instance came back the tasks stopped working again

I've added a bug in the bugbase, so hopefully the guys at Adobe will be able to shed some light on the issue.

Cheers,

Simon

Report · Jan 16, 2014

Simon, just out of curiosity, are you saying that CF has or has not been restarted since Dec 23 when you last wrote? It might be interesting/important to Adobe or others reading the thread to know for sure.

And did you compare the neo-cron.xml to confirm that it appears as you found on Dec 23? Just trying to help.

/charlie

/Charlie (troubleshooter, carehart. org)

Report · Jan 16, 2014

Hi Charlie,

Thanks for the response. The instances hadn't been restarted since the 2nd of Jan. During that period the tasks all ran successfully.

Out of interest is there a way to contact Adobe directly for something like this. I'm pretty sure we purchased support and maintenance when we got our enterprise license.

Cheers,

Simon

Report · Jan 17, 2014

I’m afraid I don’t know. I’ve never had or used that support. I’d expect that if you call Adobe though, they should be able to get you through to the right people. It may take some time on phone (hours may not be unusual, from some horror stories I hear, but I also think for the simple question of “how do I obtain support I’ve paid for” it may be a quick process.)

I found a link for gold and platinum support, if that may be what you mean you have:

https://www.adobe.com/cfusion/support/index.cfm?event=membership&returnURL=%2Fcfusion%2Fsupport%2Findex.cfm%3Fevent%3Dportal%26loc%3Den_us&loc=en_us&

which I found from the right side of this page:

http://helpx.adobe.com/contact.html?product=coldfusion&topic=using-my-product-or-service

If anyone else knows someone would proceed to get/use paid support for CF from Adobe, please do say so.

/charlie

/Charlie (troubleshooter, carehart. org)

Report · Jan 18, 2014

Thanks Charlie,

I'll try and chase them up.

I'll post any findings back here.

Cheers,

Simon

Report · Jan 21, 2014

Hi folks,

just thought I'd post something else I noticed today. A restart of the CF instances occurred again and as expected the tasks stopped completing.

I saved one of the tasks and was then distracted. When I got back to my desk that one task was running fine, the others were still failing. So you definitely have to re-save each task to get them to function again.

Do you think that lends itself to being an issue / corruption with what is stored in server memory?

I'm still trying to track down our support details, but will update with any further developments.

Simon

Report · Feb 11, 2014

Just wanted to let people know that I have been in contact with Adobe support team and they are trying to replicate the issue i'm seeing.

I'll keep people updated.

Simon

Report · Jan 09, 2015

HI Simon,

Did you make any headway with this issue? I'm dealing with something very similar.

Thanks!

Mike

Report · Jan 26, 2015

Hi Mike,

no unfortunately I was never able to get to the bottom of the issue.

Someone from Adobe contacted me initially after I raised an issue, but they never got back to me.

I ended up having to set the tasks up to run off internal URLs so that the proxy server wasn't involved.

Cheers,

Simon

Report · Jan 26, 2015

@Simon (and Mike), I know Simon you’ve moved on, but to help Mike and others reading this a year later, are you still saying the issue is that when a schedule task starts to run (as scheduled), you see the http log start the request but never finish it? And do you further confirm that if you use the CF Admin page to trigger the task, it works fine? Finally, are you confirming that this is only with URLs that go through a proxy, but those that don’t run no problem whether scheduled or triggered manually?

Mike, that’s what I understand Simon’s first notes (from 2013) to say. When you say you are dealing with something “very similar”, is it similar to that? Or some other facet of a non-working scheduled task?

And Simon was reporting this about CF10 then. Mike, is that what you’re running, too? And for either of you (Simon, if you still care to consider possibilities), can you confirm what update of CF10 (or 11) you are on, in case that may be significant?

/charlie

/Charlie (troubleshooter, carehart. org)

Report · Feb 05, 2015

I think that I've been having the same issue with scheduled tasks failing to run after a Coldfusion restart. Not sure about how or if proxy servers are involved since I haven't set one up. I also don't know what was meant by "set the tasks up to run off internal URLs" since I get a ' URL is specified in wrong format' error when trying to use a root-relative path (my URLs look like http://localhost/tasks/TaskName.cfml). The docs aren't very clear on what is allowed in the URL parameter. The scheduler admin page will say that the task ran but it doesn't actually do what I want (send reminder emails) and doesn't trigger a timeout or 500 error. Once I reschedule the tasks (programmatically via cfschedule), everything works. I haven't checked for differences before and after a restart in neo-cron.xml yet, but I'm not sure how that information will help fix this. It seems like there must be some fatal difference between how tasks are instantiated when the Coldfusion service starts up vs how it is done via cfschedule or via the admin page.

At least it's good to know that I can reschedule the tasks an have it work again after a restart. I thought that the problem was with the tasks themselves or some kind of security/permissions problem in connecting to the mail server.

Coldfusion 10 standard, update 15.

Report · Feb 12, 2015

HI Adam,

By "internal url" I mean accessing the server from in our organisation's private network. Originally I had a public fully qualified domain name, which meant it was leaving through our gateway provider and coming back in. Which in our case has to go via a proxy server.

Check you http.log to see if the task is successfully triggered and if it gets a valid response.

Cheers,

Simon

Report · Feb 12, 2015

Hi Charlie,

That's correct, for tasks that have to go via a proxy server, you see the triggered start in the http log, but you never see it finish. The odd thing is if you do anything to the task in the admin (even just opening the task and re-saving it) causes the task to run successfully. It will continue to work fine until the instance is restarted. Once the instance restarts the task will no longer work.

I was at the most current update of CF10 at the time.

Cheers,

Simon

Report · Jun 08, 2015

NOT WORKING neo-cron.xml WORKING neo-cron.xml

1. <var name="serverscheduletask#$%^default#$%^TESTTASK"> VS <var name="SERVERSCHEDULETASK#$%^DEFAULT#$%^TESTTASK">

Hi Simon,

The lowercase mode (serverscheduletask) and group (default) looks to be a CF start-up bug. What is the ticket number you filed? Task names are case-insensitive in CF but are case-sensitive in Quartz. To create consistency, Adobe had the CF Admin's tasks page and the <cfschedule> tag auto-UPPERCASE these values when creating a task. Adobe also updated the .car deploy feature to do the same for tasks being imported from a .car file. I've worked around these issues by storing all tasks' attribute values in a db table, and then onApplicationStart() calls a UDF that uses <cfschedule> to create the tasks from the db-stored values. The lowercase values in the non-working neo-cron.xml are likely causing a problem w/ their logic that handles proxied tasks.

Thanks!,

-Aaron

P.S. Charlie, that was some good thinking about comparing the neo-cron.xml files 😃

Report · May 12, 2015

Simon,

I’m quite a bit late to this post, but my organization had what appeared to be the same issue that you were experiencing. We were specifying the proxy server and port on each of our scheduled tasks. They would work fine until either the ColdFusion service was restarted or the server was restarted. Once that happened, none of our jobs would run. We would then go into each job manually – like you – and submit the jobs and they would begin to run fine. That is, until the next restart.

What we discovered to correct this is a simple fix. Go into ColdFusion Administrator and under Server Settings/Java and JVM, you will see an area called JVM Arguments. You need to add the following to the arguments:

-Dhttp.proxyHost=111.222.333.444

-Dhttp.proxyPort=1234

Make sure that you don’t forget the beginning dash and you put in your server’s IP address and port. Save the settings and restart the ColdFusion service.

I hope this helps someone – it took quite a while to figure this one out.

Barry