We recently upgraded from ColdFusion 8 Standard edition to ColdFusion 9 Enterprise edition. Since also migrated to new hardware and a new OS we decided to go with a new install instead of an upgrade. The install/migration went reasonably smoothly and as quickly as you can say "Copy my neo*.xml files, please" we were up and running on the new platform.

Then, a funny thing happened. We started to see duplicate scheduled tasks running.

A-ha! you say, the old "You forgot to stop your CF8 server and your scheduled tasks ARE running twice" ploy. It's a good assumption, and something that might admit has happened to me during past migrations. Unfortunately we moved onto brand new hardware with only our new ColdFusion instance running and the old server was offline, which meant this scenario was pretty unlikely. After spending some quality time with Google and coming up with empty search results I turned to the teachings of my favorite ColdFusion Server Guru, Charlie Arehart. To paraphrase one of his many lessons, "Look to the Log Files".

And look I did. And looked. And looked. And looked some more. Along the way we found all sorts of interesting things that helped us improve performance and identify longstanding issues - go us! For awhile I thought it was related to running out of memory but that was a big giant red herring. But the tasks were still duplicating - sometimes twice, three times, even four times. Restarting the instance always took care of the problem but it didn't bring me any closer to the cause. So, I took another look at the log files, in particular a pattern that showed up whenever duplicated tasks started to occur. Here's an excerpt from the scheduler log file:

view plain print about
1"Information","scheduler-4","05/28/12","22:10:00",,"[App_Seq - Imports Late Night Run] Executing at Mon May 28 22:10:00 PDT 2012"
2"Information","scheduler-6","05/28/12","22:10:00",,"[Run Distribution List] Executing at Mon May 28 22:10:00 PDT 2012"
3"Information","scheduler-6","05/28/12","22:10:00",,"[Run Distribution List] Rescheduling for :Mon May 28 22:12:00 PDT 2012 Now: Mon May 28 22:10:00 PDT 2012"
4"Information","scheduler-7","05/28/12","22:12:00",,"[Run Distribution List] Executing at Mon May 28 22:12:00 PDT 2012"
5[...]
6"Information","scheduler-6","05/28/12","22:12:00",,"[App_Seq - Imports Late Night Run] Activating2 on Mon May 28 22:12:00 PDT 2012 To run on Mon May 28 22:14:00 PDT 2012"
7"Information","scheduler-7","05/28/12","22:12:00",,"[Run Distribution List] Rescheduling for :Mon May 28 22:14:00 PDT 2012 Now: Mon May 28 22:12:00 PDT 2012"
8"Information","scheduler-6","05/28/12","22:12:00",,"[App_Seq, Tags] Activating2 on Mon May 28 22:12:00 PDT 2012 To run on Mon May 28 22:13:00 PDT 2012"
9[...]
10"Information","scheduler-7","05/28/12","22:13:00",,"[App_Seq, Tags] Executing at Mon May 28 22:13:00 PDT 2012"
11"Information","scheduler-7","05/28/12","22:13:00",,"[App_Seq, Tags] Rescheduling for :Mon May 28 22:17:00 PDT 2012 Now: Mon May 28 22:13:00 PDT 2012"
12"Information","scheduler-1","05/28/12","22:14:00",,"[Run Distribution List] Executing at Mon May 28 22:14:00 PDT 2012"
13"Information","scheduler-7","05/28/12","22:14:00",,"[Run Distribution List] Executing at Mon May 28 22:14:00 PDT 2012"
14"Information","scheduler-0","05/28/12","22:14:00",,"[App_Seq - Imports Late Night Run] Executing at Mon May 28 22:14:00 PDT 2012"
15"Information","scheduler-7","05/28/12","22:14:02",,"[Run Distribution List] Rescheduling for :Mon May 28 22:16:00 PDT 2012 Now: Mon May 28 22:14:02 PDT 2012"
16"Information","scheduler-1","05/28/12","22:14:02",,"[Run Distribution List] Rescheduling for :Mon May 28 22:16:00 PDT 2012 Now: Mon May 28 22:14:02 PDT 2012"

At 22:11:00 everything is fine. Then, at 22:12:00 you see the tasks include "Activating2" - as if someone had updated or initialized the scheduled task configuration file. Once that happens you'll see that the next entry at 22:14:00 has entries for the same task on two different threads. So what happened? It turns out that there's a server setting, "Watch configuration files for changes (check every xxx seconds)". The description for the setting includes the phrase "Most installations should not enable this feature." This is quite the understatement! It's still a mystery how this setting got enabled during our installation but nevertheless, there it was. Enabling this setting "Causes ColdFusion to watch its configuration files and automatically reload them if they change. This is required if you deploy ColdFusion in a Websphere ND vertical cluster, as multiple instances of ColdFusion share the same configuration files." What it ALSO does is initialize the scheduled tasks file and startup any scheduled tasks without checking to see if they are already running. In our case it generally duplicated tasks that run quite often, say every 2 minutes, since they had a greater chance of actively running when the file was re-initialized. In this particular case you can see that [Run Distribution List] gets duplicated.

Once we found this, the solution was as simple as changing the setting and restarting the instance. The issue cleared up immediately and (thanks in part to all the work we did along the way investigating and resolving other issues we found in the server logfiles) we're able to enjoy the new configuration that much more! This leaves me with one lingering question - what do you do if you ARE running ColdFusion in a Websphere ND vertical cluster? Say "No, thanks" to ColdFusion scheduled tasks?