What am I trying to do?
We have a few SCCM clients, mostly publicly facing websites running on Windows Server 2008 R2's IIS 7.5, that are monitored by a system called XYmon. We have recently noticed these servers are rebooting after installing their monthly Windows Updates about an hour early. There is a certain amount of delay inherent in the SCCM Client Actions and the monitoring system but XYmon loses connection with these machines right around 19:20-19:30ish whereas the rest of the monitored machines seem to reboot about an hour later around 20:20-20:30.
The Maintenance Window that I expect to be applied starts at 20:00 and ends at 22:00 and reoccurs every Thursday.
I am trying to figure out why these machines are installing their updates an hour early. I know that multiple Maintenance Windows are "union-ed" or merged so I suspect there is another Maintenance Window that is also applying to these clients.
These machines are also in a non-domain joined DMZ so I'm not going to rule out any timezone / clock skew issues either.
What did I try in order to make it happen?
I figured the timezone / clock skew issue was the most likely but both machines were in the correct timezone, had synchronized time and managed to handle the Daylight Savings change that happened on March 8th appropriately.
My next hypothesis is that we had an errant or old Maintenance Window that was applying to a Collection these machines were in. This seems a little unlikely to me since there is another machine that should be all the same Collections which reboots at the correct time of 20:00-ish.
Let's make sure the client is actually rebooting when the monitoring system says it is!
If I check a client, systeminfo
shows the boot time at 19:22. The Event Log seems to collaborate this:
Log Name: System
Source: USER32
Date: 3/12/2015 7:21:02 PM
Event ID: 1074
Task Category: None
Level: Information
Keywords: Classic
User: SYSTEM
Computer: HOST09
Description:
The process C:\Windows\CCM\CcmExec.exe (HOST09) has initiated the restart of computer HOST09 on behalf of user NT AUTHORITY\SYSTEM for the following reason: No title for this reason could be found
Reason Code: 0x80020001
Shutdown Type: restart
Comment: Your computer will restart at 03/12/2015 07:21:02 PM to complete the installation of applications and software updates.
Did it reboot because of SCCM's Windows Updates?
If I dig into the UpdatesHandler.log
the answer is a big old "yes":
Initiating updates scan for checking applicability. UpdatesHandler 3/12/2015 7:00:00 PM 6472 (0x1948)
Successfully initiated scan. UpdatesHandler 3/12/2015 7:00:00 PM 6472 (0x1948)
Updates scan completion received, result = 0x0. UpdatesHandler 3/12/2015 7:00:00 PM 8396 (0x20CC)
Initiating updates scan for checking applicability. UpdatesHandler 3/12/2015 7:00:02 PM 10160 (0x27B0)
Method (Apply) called from SDM. UpdatesHandler 3/12/2015 7:00:02 PM 8888 (0x22B8)
Starting job with id = {7DD179F1-1B94-4ADB-A5F1-08E9A000709F} UpdatesHandler 3/12/2015 7:00:02 PM 8888 (0x22B8)
Successfully initiated scan. UpdatesHandler 3/12/2015 7:00:02 PM 10160 (0x27B0)
Updates scan completion received, result = 0x0. UpdatesHandler 3/12/2015 7:00:02 PM 8396 (0x20CC)
Initiating Scan. Forced = (0) UpdatesHandler 3/12/2015 7:00:02 PM 8888 (0x22B8)
Successfully initiated scan for job ({7DD179F1-1B94-4ADB-A5F1-08E9A000709F}). UpdatesHandler 3/12/2015 7:00:02 PM 8888 (0x22B8)
Scan completion received for job ({7DD179F1-1B94-4ADB-A5F1-08E9A000709F}). UpdatesHandler 3/12/2015 7:00:02 PM 8396 (0x20CC)
Evaluating status of the updates for the job ({7DD179F1-1B94-4ADB-A5F1-08E9A000709F}). UpdatesHandler 3/12/2015 7:00:02 PM 8396 (0x20CC)
Initiating download for the job ({7DD179F1-1B94-4ADB-A5F1-08E9A000709F}). UpdatesHandler 3/12/2015 7:00:02 PM 8396 (0x20CC)
Bundle update (038c4fc9-664f-45e5-b838-f7263ffc4512) is requesting download from child updates for action (INSTALL) UpdatesHandler 3/12/2015 7:00:02 PM 8396 (0x20CC)
The 'ServiceWindowManager.log` shows that that Maintenance Window was applied at 19:00:
Active Service Windows List has 1 windows ServiceWindowManager 3/12/2015 7:28:13 PM 2404 (0x0964)
Service Window with ID = {F51051BF-90E8-4ED7-BA06-F74F9E74A098} having Starttime=03/12/15 19:00:00 ServiceWindowManager 3/12/2015 7:28:13 PM 2404 (0x0964)
Duration is 0 days, 08 hours, 00 mins, 00 secs ServiceWindowManager 3/12/2015 7:28:13 PM 2404 (0x0964)
OK... Where did that Maintenance Window come from?
A little bit of SQL should show me all the Maintenance Windows applied to a particular SCCM client:
select
v_FullCollectionMembership.Name as Computername ,v_Collection.Name as CollectionName,
v_ServiceWindow.Description as "Next Maintanance Window"
from v_ServiceWindow
inner join v_FullCollectionMembership on (v_FullCollectionMembership.CollectionID = v_ServiceWindow.CollectionID)
inner join v_Collection on (v_Collection.CollectionID = v_FullCollectionMembership.CollectionID)
order by Computername
and I get the following results:
Computername CollectionName Next Maintanance Window
HOST09 Default Maintenance Window Occurs on 9/15/2013 1:00 AM
HOST09 Weekly Maintenance Window - Thursday Occurs every 1 weeks on Thursday effective 11/1/2013 8:00 PM
A bit of explanation is in order: All our SCCM clients belong to a Collection that gets assigned a Default Maintenance Window that only occurs once and is in the past. This prevents Collection membership changes and untimely client policy requests from causing clients that have held off actions from immediately performing them. However, since the Maintenance Windows are "union-ed" the Weekly Maintenance Window should apply... at 20:00.
On a hunch I dumped all the Collections this client was in and then went and checked to see if they have Maintenance Windows assigned to them:
SELECT dbo.v_Collection.Name
FROM dbo.v_FullCollectionMembership INNER JOIN dbo.v_Collection ON dbo.v_FullCollectionMembership.CollectionID = dbo.v_Collection.CollectionID
WHERE (LOWER(dbo.v_FullCollectionMembership.Name) = LOWER('HOST09'))
Long story short. They don't.
What results did you expect?
I really expected to see a Collection that had a Maintenance Window applied to it that started at 19:00 and unless my SQL is bad and I missed it I guess that is not what's going on here.
The fact that it is one hour early really also inclines me to think it could be an issue with timezones or clock skew but that looks to be expected as well.
I still think both my hypotheses are decent and have not been refuted but I do not know how to gather more information to make a determination about them. Any ideas on how I should proceed with troubleshooting?
Is there something else I should consider? What other things could cause this?
EDIT:
I checked the Software Update Group for this month's Software Updates and there is a deadline set for 03/10/15 at 20:53 but the deadline behavior for activities to be performed outside the maintenance window is disabled for both Software updates installation and System restart.
As for the current time on the box, like it really does look OK but I'm just checking Date and Time in the Control Panel: