Task scheduler ran a task twice

Update: This has now happened two days in a row.

Update: XML of scheduled tasks and images now included.

Two servers located in London, both Windows 2012, have a scheduled task set to run at 3pm Monday to Friday. This has been set up for the last 5 months without a problem.

However, on Monday the 28th of August they both ran the scheduled task at 3pm and then again at 4pm. When it was first reported, I thought it was too much of a coincidence to be the day after the clocks had gone back an hour. However, I’m failing in being able to explain why it has happened and if it is related to the clock change at all.

The relevant logs from one server (the logs for the other follow this pattern as well):

Event 129 15:00:20 Task Scheduler launch task "\3pm", instance "C:\Program Files (x86)\PHP\v5.4\php.exe" with process ID 2388.

Event 100 15:00:20 Task Scheduler started "{75a3590f-dec1-4dee-bd27-73d63a50a9d7}" instance of the "\3pm" task for user "x\y".

Event 200 15:00:20 Task Scheduler launched action "C:\Program Files (x86)\PHP\v5.4\php.exe" in instance "{75a3590f-dec1-4dee-bd27-73d63a50a9d7}" of task "\3pm".

Event 201 15:00:23 Task Scheduler successfully completed task "\3pm" , instance "{75a3590f-dec1-4dee-bd27-73d63a50a9d7}" , action "C:\Program Files (x86)\PHP\v5.4\php.exe" with return code 0.

Event 129 16:00:20 Task Scheduler launch task "\3pm", instance "C:\Program Files (x86)\PHP\v5.4\php.exe" with process ID 1224.

Event 100 16:00:20 Task Scheduler started "{3dd46ca9-c525-4796-86b5-5e513fd45f26}" instance of the "\3pm" task for user "x\y".

Event 200 16:00:20 Task Scheduler launched action "C:\Program Files (x86)\PHP\v5.4\php.exe" in instance "{3dd46ca9-c525-4796-86b5-5e513fd45f26}" of task "\3pm".

Event 201 16:00:23 Task Scheduler successfully completed task "\3pm" , instance "{3dd46ca9-c525-4796-86b5-5e513fd45f26}" , action "C:\Program Files (x86)\PHP\v5.4\php.exe" with return code 0.

I've seen this question Scheduled task running twice from time to time which points to a bug at http://support.microsoft.com/kb/2461249 being the cause. However, this doesn't include Server 2012 in it's list of problem operating systems.

I’m struggling to explain this, can anyone else?

The XML export for the scheduled task is:

<?xml version="1.0" encoding="UTF-16"?>
<Task version="1.2" xmlns="http://schemas.microsoft.com/windows/2004/02/mit/task">
  <RegistrationInfo>
    <Date>2013-04-16T14:04:17.4897806</Date>
    <Author>x\y</Author>
  </RegistrationInfo>
  <Triggers>
    <CalendarTrigger>
      <StartBoundary>2013-04-17T15:00:20</StartBoundary>
      <Enabled>true</Enabled>
      <ScheduleByWeek>
        <DaysOfWeek>
          <Monday />
          <Tuesday />
          <Wednesday />
          <Thursday />
          <Friday />
        </DaysOfWeek>
        <WeeksInterval>1</WeeksInterval>
      </ScheduleByWeek>
    </CalendarTrigger>
  </Triggers>
  <Principals>
    <Principal id="Author">
      <UserId>x\y</UserId>
      <LogonType>Password</LogonType>
      <RunLevel>LeastPrivilege</RunLevel>
    </Principal>
  </Principals>
  <Settings>
    <MultipleInstancesPolicy>IgnoreNew</MultipleInstancesPolicy>
    <DisallowStartIfOnBatteries>true</DisallowStartIfOnBatteries>
    <StopIfGoingOnBatteries>true</StopIfGoingOnBatteries>
    <AllowHardTerminate>true</AllowHardTerminate>
    <StartWhenAvailable>false</StartWhenAvailable>
    <RunOnlyIfNetworkAvailable>false</RunOnlyIfNetworkAvailable>
    <IdleSettings>
      <StopOnIdleEnd>true</StopOnIdleEnd>
      <RestartOnIdle>false</RestartOnIdle>
    </IdleSettings>
    <AllowStartOnDemand>true</AllowStartOnDemand>
    <Enabled>true</Enabled>
    <Hidden>false</Hidden>
    <RunOnlyIfIdle>false</RunOnlyIfIdle>
    <WakeToRun>false</WakeToRun>
    <ExecutionTimeLimit>P3D</ExecutionTimeLimit>
    <Priority>7</Priority>
  </Settings>
  <Actions Context="Author">
    <Exec>
      <Command>"C:\Program Files (x86)\PHP\v5.4\php.exe"</Command>
      <Arguments>-f "c:\a.php"</Arguments>
    </Exec>
  </Actions>
</Task>

Trigger Configuration for the scheduled taskHistory for the scheduled task

29 October 17:00 - Update - Both servers have again run the scheduled task at 15:00 and 16:00. I've now updated the php file that is run by the scheduler to not actually do anything whilst I'm going through trying to solve this. I'm planning on restarting one server to see if this changes anything tomorrow.

30 October 08:25 - Update - When exporting the task XML I remembered that I hadn't included the fact that the scheduled task on second server was created by importing the XML of the task created on the first. The only difference between the two tasks is the path of the php file they are executing and the user account that they are running as.

30 October 16:30 - Update - The server that has been restarted is not showing this behaviour any more, the scheduled task ran once on it. I'll wait a few days before restarting the second server in case anyone has any ideas on diagnosing why / how it happened

06 November 18:00 - Update - We applied all of the updates to the second server and restarted. We assumed that this would solve the problem, however the 3pm ran twice again - once at 3pm and again at 4pm. I looked at other scheduled jobs and they ran only once.


Solution 1:

We just noticed the same issue on our production servers (also Windows Server 2012), which occurred this week. It also started after our clocks went back one hour (which was November 3, 2013, here in Toronto).

Update as at Nov 12, 2013:

  • Rebooting did not work (tasks continued to run twice)
  • Exporting and re-importing the tasks did not work (tasks continued to run twice)
  • Manually re-creating the task in the GUI does fix the issue

Also, after further discusssions with Microsoft (by our sys admin), Microsoft said: "...the issue was identified in Windows Server 2012 and has been fixed only in the next release of Windows which is Windows 8.1 / Windows Server 2012 R2".

Solution 2:

I've had this problem crop up this week since the DST changeover. I know this isn't a great answer, but deleting and recreating the job appears to solve the problem. I tested on a couple of jobs that have been duplicating over night and the recreated jobs did not duplicate.

Solution 3:

We could reproduce the error when the job was scheduled to UTC+0 (Windows 2012 R2 server).
E.g. We had a job running at wrong dates which was scheduled at 2 am.
As our timezone is UTC+2, the job ran at UTC+0.
It seems that Windows has some rounding issues. Perhaps it uses UTC internally and if the job runs exactly at UTC+0, some rounding errors or race conditions cause the job to run on the wrong dates.
We also saw jobs, which run as planned but after reboot, reported:

The operator or administrator has refused the request (0x800710E0)

After changing the scheduled time to e.g. 2:02 am, the errors disappeared.