4

I've been having an intermittent problem for some time now with the Windows Task Scheduler that I can't work out. I use the task scheduler to run a C# app I've written that has various plugins used to ensure production systems are working.

This task scheduler itself is actually a production system so I have one simple task that executes every 8 minutes to notify an external monitoring system that the task scheduler is still up. If this external service fails to receive an "all-clear" at least once every 15 minutes (or so I don't remember the exact number right now) it will message us that the monitoring system is down.

In the past we've had intermittent "down" messages from time to time and each time I've investigated the cause I was unable to find any problems. So this time I wanted to ask the StackOverflow community since it doesn't look like I'll have luck on my own.

This morning at 2:32 AM the task fired (exactly 8 minutes after the previous firing) however the task didn't fire again until 3:28. There are no errors that I can see in the Event Viewer at this time. When I look at the Task Scheduler log there are no errors there either. Here is what the log looks like though:

Information 6/11/2011 3:28:56 AM    102 Task completed  (2) d6cf2412-269e-48bf-9f40-4a863347baad
Information 6/11/2011 3:28:56 AM    201 Action completed    (2) d6cf2412-269e-48bf-9f40-4a863347baad
Information 6/11/2011 3:28:55 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:55 AM    200 Action started  (1) d6cf2412-269e-48bf-9f40-4a863347baad
Information 6/11/2011 3:28:55 AM    100 Task Started    (1) d6cf2412-269e-48bf-9f40-4a863347baad
Information 6/11/2011 3:28:55 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:55 AM    107 Task triggered on scheduler Info    d6cf2412-269e-48bf-9f40-4a863347baad
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) b91fe5ce-39ef-42fb-adbe-bd8be012c00a
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) b91fe5ce-39ef-42fb-adbe-bd8be012c00a
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) 556c07dc-2724-4a21-a97e-dc4abd56f94d
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) 556c07dc-2724-4a21-a97e-dc4abd56f94d
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) 79328289-f742-49dd-aa0d-c3d05db50895
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) 79328289-f742-49dd-aa0d-c3d05db50895
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) 19743755-47b6-4b98-9bec-052193be9496
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) 19743755-47b6-4b98-9bec-052193be9496
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) c165754f-e3e6-4176-a327-11f9c06c39a5
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) c165754f-e3e6-4176-a327-11f9c06c39a5
Information 6/11/2011 3:28:15 AM    102 Task completed  (2) 0e62ad3e-1f6e-40c0-9155-19f0108dee22
Information 6/11/2011 3:28:15 AM    201 Action completed    (2) 0e62ad3e-1f6e-40c0-9155-19f0108dee22
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) 0e62ad3e-1f6e-40c0-9155-19f0108dee22
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) c165754f-e3e6-4176-a327-11f9c06c39a5
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) 19743755-47b6-4b98-9bec-052193be9496
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) 79328289-f742-49dd-aa0d-c3d05db50895
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) 556c07dc-2724-4a21-a97e-dc4abd56f94d
Information 6/11/2011 3:28:10 AM    129 Created Task Process    Info    
Information 6/11/2011 3:28:10 AM    200 Action started  (1) b91fe5ce-39ef-42fb-adbe-bd8be012c00a
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) 0e62ad3e-1f6e-40c0-9155-19f0108dee22
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) c165754f-e3e6-4176-a327-11f9c06c39a5
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) 19743755-47b6-4b98-9bec-052193be9496
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) 79328289-f742-49dd-aa0d-c3d05db50895
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) 556c07dc-2724-4a21-a97e-dc4abd56f94d
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    100 Task Started    (1) b91fe5ce-39ef-42fb-adbe-bd8be012c00a
Information 6/11/2011 3:28:10 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    0e62ad3e-1f6e-40c0-9155-19f0108dee22
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    c165754f-e3e6-4176-a327-11f9c06c39a5
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    19743755-47b6-4b98-9bec-052193be9496
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    79328289-f742-49dd-aa0d-c3d05db50895
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    556c07dc-2724-4a21-a97e-dc4abd56f94d
Information 6/11/2011 3:28:10 AM    107 Task triggered on scheduler Info    b91fe5ce-39ef-42fb-adbe-bd8be012c00a
Information 6/11/2011 2:32:56 AM    102 Task completed  (2) 16e4f2c3-a340-410a-9c14-4bfe0861fdd5
Information 6/11/2011 2:32:56 AM    201 Action completed    (2) 16e4f2c3-a340-410a-9c14-4bfe0861fdd5
Information 6/11/2011 2:32:55 AM    129 Created Task Process    Info    
Information 6/11/2011 2:32:55 AM    200 Action started  (1) 16e4f2c3-a340-410a-9c14-4bfe0861fdd5
Information 6/11/2011 2:32:55 AM    100 Task Started    (1) 16e4f2c3-a340-410a-9c14-4bfe0861fdd5
Information 6/11/2011 2:32:55 AM    319 Task Engine received message to start task  (1) 
Information 6/11/2011 2:32:55 AM    107 Task triggered on scheduler Info    16e4f2c3-a340-410a-9c14-4bfe0861fdd5

Seems kind of strange. I also have two other C# apps that run and check something each hour on the hour using task scheduler. If I look at the history for those I can see that they didn't execute at 3 AM either! They all waited until 3:28 to start as well.

If I look at "tasks completed" in the Event Viewer it shows that only one task was able to run between the 2:32 AM to 3:28 AM time period. The task was "\Microsoft\Windows\RAC\RACAgent"

And here's what it looked like:

Information 6/11/2011 3:18:09 AM    102 Task completed  (2) 00c53a85-ba20-4666-80db-fbbe2492c0ad
Information 6/11/2011 3:18:09 AM    201 Action completed    (2) 00c53a85-ba20-4666-80db-fbbe2492c0ad
Information 6/11/2011 3:18:08 AM    129 Created Task Process    Info    
Information 6/11/2011 3:18:08 AM    200 Action started  (1) 00c53a85-ba20-4666-80db-fbbe2492c0ad
Information 6/11/2011 3:18:08 AM    100 Task Started    (1) 00c53a85-ba20-4666-80db-fbbe2492c0ad
Information 6/11/2011 3:18:08 AM    319 Task Engine received message to start task  (1) 

I appreciate any ideas anyone may have.

omatase
  • 141
  • 2
  • Did you check the event log for other activity in the time window, like patching/reboots? Check for services stopped/started. No daylight saving time events? Power failure, server running on UPS? – SqlACID Jun 11 '11 at 19:20
  • Yes, I checked all of these things before with other cases and in this case as well. There seems to be no evidence of trouble during that period of time. – omatase Jun 13 '11 at 16:22

2 Answers2

1

Is your scheduled task running on a hyper-v virtual server?

It may have been paused by its hyper-v host for maintenance (backups, lack of shared resources, ...).

oleschri
  • 317
  • 1
  • 12
1

Are you running any backups during the time? I had a system running a system-wide backup, and the scheduled task would not complete (and this is when the task actually ran) until the backup finished.

northben
  • 382
  • 1
  • 4
  • 13