First published on TECHNET on Aug 25, 2016
~ Ibrahim Aladwan
Hello everyone, my name is Ibrahim Aladwan and I’m a support engineer on the Configuration Manager team. Today I’d like to take a minute and go through the update process in System Center Configuration Manager current branch (ConfigMgr 1511, ConfigMgr 1602, etc.) and demonstrate how things work from the client side of things.
Overview
When a client computer in the target collection for a deployment receives machine policy, the Software Update Client Agent starts an evaluation scan. The client agent downloads the content for required software updates from a distribution point to the local client cache at the Software available time setting for the deployment, and then the software updates are available to install. This differs for software updates in optional deployments (deployments that do not have an installation deadline), as they are not downloaded until a user manually starts the installation. When the configured deadline passes, the Software Updates client agent performs a scan to verify that the software updates are still required, and assuming they are, it then checks the local cache on the client computer to verify that the software update source files are still available and installs the updates. If the content was deleted from the client cache to make room for another deployment, the client re-downloads the software updates from the distribution point to the client cache. Software updates are always downloaded to the client cache regardless of the configured maximum client cache size. When the installation is complete, the client agent verifies that the software updates are no longer required, then sends a state message to the management point to indicate that the software updates are now installed on the client.
Taking a Closer Look
To get a better understanding of this, let’s take a look at the client log files and track the progress as we deploy KB 3176493. The client and site server components record process information in individual log files, and by default, client and server component logging is enabled in Configuration Manager. You can use the information in these log files to help you troubleshoot issues that might occur in your Configuration Manager environment. For additional information on these log files please refer to the following:
Technical Reference for Log Files in Configuration Manager
So here’s what KB 3176493 looks like when we start:
Software Update Scanning and Evaluation
When the Evaluation cycle is requested (manual or on schedule), entries similar to the following will appear in ScanAgent.log :
Message received: '<?xml version='1.0' ?> <UpdateSourceMessage MessageType='ScanByUpdateSource'>
<ForceScan>TRUE</ForceScan>
<UpdateSourceIDs>
<ID>{39B24983-D827-4C7C-8782-029410E9C146}</ID>
</UpdateSourceIDs>
</UpdateSourceMessage>'
ScanAgent
On the SQL Server, SQL profiler will show that Configuration Manager is executing the stored procedure MP_GetWSUSServerLocations :
RPC:Completed exec MP_GetWSUSServerLocations N'{39B24983-D827-4C7C-8782-029410E9C146}',N'167',N'FCH',N'FCH',N'0',N'server.contoso.local' System Center 2012 Configuration Manager SYSTEM NT AUTHORITY\SYSTEM 16 131 0 38 1816 72 8/10/2016 1:24:05 AM
0X000000000700000032004D0050005F0047006500740057005300550053005300650072007600650072004C006F0063006100740069006F006E007300720000
This value is then returned to LocationService.log :
Calling back with the following WSUS locations LocationServices
8/10/2016 1:24:05 AM 7956 (0x1F14) WSUS Path=' http://server.contoso.local:8530' , Server='server.contoso.local', Version='167' LocationServices
ScanAgent.log also shows the following:
*****Policy Change notification received for ToolUniqueID={39B24983-D827-4C7C-8782-029410E9C146} ScanAgent 8/10/2016 1:24:01 AM
*****ScanByUpdates request received with ForceReScan=0, ScanOptions=0x00000008, WSUSLocationTimeout = 604800 ScanAgent
ScanAgent then checks the update source and Time-To-Live (TTL) settings for the last scan results and submits a request for WSUS server location, then LocationService retrieves the WSUS location from the Management Point and returns the URL and the server name, as seen here in ScanAgent.log :
ScanJob({DCB47C9A-3D45-4495-8116-5EE9E0F3B4D2}): - - - - - -Locations requested for ScanJobID={DCB47C9A-3D45-4495-8116-5EE9E0F3B4D2} (LocationRequestID={6CBEFDD4-7390-4A41-AA4D-4D3F8B72111F}), will process the scan request once locations are available. ScanAgent 8/10/2016 1:24:03 AM
*****WSUSLocationUpdate received for location request guid={6CBEFDD4-7390-4A41-AA4D-4D3F8B72111F} ScanAgent
Next, the Windows Update scan is initiated and we see the following in ScanAgent.log :
*****ScanByUpdates request received with ForceReScan=0, ScanOptions=0x00000008, WSUSLocationTimeout = 604800 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
- - -Evaluating Update Status... ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:4d52d21e-e4a1-4043-bcda-69a696b2b257 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:4d52d21e-e4a1-4043-bcda-69a696b2b257 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:a12fff7b-aefc-4815-ab2e-0048ada4ea9e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:a12fff7b-aefc-4815-ab2e-0048ada4ea9e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:c071152f-3697-44f4-b77c-bf07519dd63e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:c071152f-3697-44f4-b77c-bf07519dd63e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:e6561a3e-2ee6-48e4-8770-78068771cfcb ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:e6561a3e-2ee6-48e4-8770-78068771cfcb ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
State messages are created for each software update that changed in compliance state, then state messages are sent to the Management Point as seen in StateMessage.log :
Adding message with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 to WMI StateMessage 8/10/2016 1:25:53 AM 5148 (0x141C)
State message(State ID : 2) with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 has been recorded for SYSTEM StateMessage 8/10/2016 1:25:53 AM 5148 (0x141C)
Successfully forwarded State Messages to the MP StateMessage 5148 (0x141C)
We also see entries similar to the following in WUAHandler.log :
Its a WSUS Update Source type ({39B24983-D827-4C7C-8782-029410E9C146}), adding it. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Existing WUA Managed server was already set ( http://FC-CM01.fourthcoffee.local:8530) , skipping Group Policy registration. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Added Update Source ({39B24983-D827-4C7C-8782-029410E9C146}) of content type: 2 WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Scan results will include superseded updates only when they are superseded by service packs and definition updates. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Search Criteria is (DeploymentAction=* AND Type='Software') OR (DeploymentAction=* AND Type='Driver') WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Async searching of updates using WUAgent started. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Async searching completed. WUAHandler 8/10/2016 1:25:52 AM 1308 (0x051C)
Successfully completed scan. WUAHandler 8/10/2016 1:25:52 AM 5148 (0x141C)
Installation
When a client computer in the target collection for the deployment receives the machine policy, machine policy including new or changed deployment assignment policy is downloaded. UpdatesDeployment.log receives modification event and triggers evaluation and installation process, as shown here:
Assignment {b8cf0a9f-3b46-4ce7-9712-b281aa88b953} has total CI = 16 UpdatesDeploymentAgent 8/10/2016 1:24:02 AM 7956 (0x1F14)
OnPolicyModify for assignment ({b8cf0a9f-3b46-4ce7-9712-b281aa88b953})... UpdatesDeploymentAgent 8/10/2016 1:24:02 AM 7956 (0x1F14)
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Name (Cumulative Update for Windows 10 Version 1511 (KB3176493)) ArticleID (3176493) added to the targeted list of deployment ({b8cf0a9f-3b46-4ce7-9712-b281aa88b953}) UpdatesDeploymentAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Raising client SDK event for class CCM_SoftwareUpdate, instance CCM_SoftwareUpdate.UpdateID="Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257", actionType 11l, value NULL, user NULL, session 4294967295l, level 0l, verbosity 30l UpdatesDeploymentAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
UpdatesStore will check the status of each update and look for the source, then CIDownloader determines applicability for each update. This is shown in UpdateStore.log :
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Missing, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 1:25:53 AM 4316 (0x10DC)
Querying update status of 2 updates. UpdatesStore 8/10/2016 3:10:47 AM 6232 (0x1858)
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Missing, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 3:26:49 AM 6232 (0x1858)
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Installed, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 5:08:07 AM 3628 (0x0E2C)
UpdatesHandler then retrieves download settings and software update relationships, then calls to download content.
Entries similar to the following appear in UpdatesHanlder.log :
Bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) is requesting download from child updates for action (INSTALL) UpdatesHandler 8/10/2016 1:26:41 AM 7556 (0x1D84)
StateCore - bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) state changed from (WAIT_CONTENTS) to (EXECUTE_READY) as child update state changed UpdatesHandler 8/10/2016 3:10:43 AM 6548 (0x1994)
Bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) is requesting download from child updates for action (INSTALL) UpdatesHandler 8/10/2016 3:10:48 AM 4432 (0x1150)
Entries similar to the following appear in WUAHandler.log :
Going to search using WSUS update source. WUAHandler 8/10/2016 3:10:49 AM 3688 (0x0E68)
Synchronous searching of all updates started... WUAHandler 8/10/2016 3:10:49 AM 3688 (0x0E68)
Successfully completed synchronous searching of updates. WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
1. Update: 4d52d21e-e4a1-4043-bcda-69a696b2b257, 205 BundledUpdates: 1 WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
Update: a12fff7b-aefc-4815-ab2e-0048ada4ea9e, 200 BundledUpdates: 0 WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
1. Update (Missing): Cumulative Update for Windows 10 Version 1511 (KB3176493) (4d52d21e-e4a1-4043-bcda-69a696b2b257, 205) WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
Async installation of updates started. WUAHandler 8/10/2016 3:12:58 AM 3688 (0x0E68)
Update 1 (4d52d21e-e4a1-4043-bcda-69a696b2b257) finished installing (0x00000000), Reboot Required? Yes WUAHandler 8/10/2016 3:26:35 AM 4708 (0x1264)
Async install completed. WUAHandler 8/10/2016 3:26:46 AM 5660 (0x161C)
Installation of updates completed. WUAHandler 8/10/2016 3:26:46 AM 6232 (0x1858)
Then we get the content location and the following is logged in LocationService.log :
Calling back with the following distribution points LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Distribution Point=' http://FC-CM01.fourthcoffee.local/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e', Locality='LOCAL', DPType='SERVER', Version='8325', Capabilities='<Capabilities SchemaVersion="1.0"><Property Name="SSLState" Value="0"/></Capabilities>', Signature=' http://FC-CM01.fourthcoffee.local/SMS_DP_SMSSIG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e.1.tar', ForestTrust='TRUE', LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Filtering locations for request {E68DF60D-00D0-4330-9ECE-8742B48CB801}. LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Then software update content is downloaded to the cache and the following is logged in DataTransferService.log :
UpdateURLWithTransportSettings(): OLD URL - http://FC-CM01.fourthcoffee.local/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
UpdateURLWithTransportSettings(): NEW URL - http://FC-CM01.fourthcoffee.local:80/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
DTSJob {252AF5CA-A261-49FA-82DB-50556214AEAC} created to download from ' http://FC-CM01.fourthcoffee.local:80/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e' to 'C:\Windows\ccmcache\1b'. DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
DTSJob {252AF5CA-A261-49FA-82DB-50556214AEAC} in state 'DownloadingManifest'. DataTransferService 8/10/2016 3:09:02 AM 6548 (0x1994)
GET: Host=FC-CM01.fourthcoffee.local, Path=/SMS_DP_SMSPKG$/a12fff7b-aefc-4815-ab2e-0048ada4ea9e, Port=80, Protocol=http, Flags=133, Options=224 DataTransferService 8/10/2016 3:09:02 AM 4320 (0x10E0)
UpdatesDeploymentAgent then raises a state message (download complete) and calls WUAHandler to handle the software update installation via WUA. You can see this via the following entries in UpdatesDeployment.log :
ApplyCIs - JobId = {301925A8-283F-42AE-95F0-272A10359929} UpdatesDeploymentAgent 8/10/2016 3:10:47 AM 4432 (0x1150)
…...
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Progress: Status = ciStateInstalling, PercentComplete = 10, DownloadSize = 0, Result = 0x0 UpdatesDeploymentAgent 8/10/2016 3:19:31 AM 4432 (0x1150)
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Progress: Status = ciStateInstalling, PercentComplete = 100, DownloadSize = 0, Result = 0x0 UpdatesDeploymentAgent 8/10/2016 3:24:54 AM 3688 (0x0E68)
CUpdatesJob({301925A8-283F-42AE-95F0-272A10359929}): Job completion received. UpdatesDeploymentAgent 8/10/2016 3:26:50 AM 4320 (0x10E0)
CUpdatesJob({301925A8-283F-42AE-95F0-272A10359929}): Delete job from WMI UpdatesDeploymentAgent 8/10/2016 3:26:50 AM 4320 (0x10E0)
WUA then installs the updates and we see the following in CBS.log :
2016-08-10 03:13:02, Info CBS Opened cabinet package, package directory: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\, sandbox location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\, cabinet location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\Windows10.0-KB3176493-x86.cab, manifest location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\update.mum
2016-08-10 03:14:36, Info CBS Extracting all files from cabinet \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\Cab_1_for_KB3176493.cab
Next, state messages are created for each software update that changed in compliance state, and these state messages are sent to the management point as seen in StateMessage.log :
State message(State ID : 3) with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 has been recorded for SYSTEM StateMessage 8/10/2016 5:08:07 AM 3784 (0x0EC8)
At this point the updates are installed and the hierarchy is updated.
More Information
For more information about state message and ID, please see the table below.
Ref: State Messages in Configuration Manager 2007
For more information on Software Updates, see Introduction to Software Updates in Configuration Manager
Ibrahim Aladwan , Support Engineer
Microsoft System Center Configuration Manager
~ Ibrahim Aladwan
Hello everyone, my name is Ibrahim Aladwan and I’m a support engineer on the Configuration Manager team. Today I’d like to take a minute and go through the update process in System Center Configuration Manager current branch (ConfigMgr 1511, ConfigMgr 1602, etc.) and demonstrate how things work from the client side of things.
Overview
When a client computer in the target collection for a deployment receives machine policy, the Software Update Client Agent starts an evaluation scan. The client agent downloads the content for required software updates from a distribution point to the local client cache at the Software available time setting for the deployment, and then the software updates are available to install. This differs for software updates in optional deployments (deployments that do not have an installation deadline), as they are not downloaded until a user manually starts the installation. When the configured deadline passes, the Software Updates client agent performs a scan to verify that the software updates are still required, and assuming they are, it then checks the local cache on the client computer to verify that the software update source files are still available and installs the updates. If the content was deleted from the client cache to make room for another deployment, the client re-downloads the software updates from the distribution point to the client cache. Software updates are always downloaded to the client cache regardless of the configured maximum client cache size. When the installation is complete, the client agent verifies that the software updates are no longer required, then sends a state message to the management point to indicate that the software updates are now installed on the client.
Taking a Closer Look
To get a better understanding of this, let’s take a look at the client log files and track the progress as we deploy KB 3176493. The client and site server components record process information in individual log files, and by default, client and server component logging is enabled in Configuration Manager. You can use the information in these log files to help you troubleshoot issues that might occur in your Configuration Manager environment. For additional information on these log files please refer to the following:
Technical Reference for Log Files in Configuration Manager
So here’s what KB 3176493 looks like when we start:
Software Update Scanning and Evaluation
When the Evaluation cycle is requested (manual or on schedule), entries similar to the following will appear in ScanAgent.log :
Message received: '<?xml version='1.0' ?> <UpdateSourceMessage MessageType='ScanByUpdateSource'>
<ForceScan>TRUE</ForceScan>
<UpdateSourceIDs>
<ID>{39B24983-D827-4C7C-8782-029410E9C146}</ID>
</UpdateSourceIDs>
</UpdateSourceMessage>'
ScanAgent
On the SQL Server, SQL profiler will show that Configuration Manager is executing the stored procedure MP_GetWSUSServerLocations :
RPC:Completed exec MP_GetWSUSServerLocations N'{39B24983-D827-4C7C-8782-029410E9C146}',N'167',N'FCH',N'FCH',N'0',N'server.contoso.local' System Center 2012 Configuration Manager SYSTEM NT AUTHORITY\SYSTEM 16 131 0 38 1816 72 8/10/2016 1:24:05 AM
0X000000000700000032004D0050005F0047006500740057005300550053005300650072007600650072004C006F0063006100740069006F006E007300720000
This value is then returned to LocationService.log :
Calling back with the following WSUS locations LocationServices
8/10/2016 1:24:05 AM 7956 (0x1F14) WSUS Path=' http://server.contoso.local:8530' , Server='server.contoso.local', Version='167' LocationServices
ScanAgent.log also shows the following:
*****Policy Change notification received for ToolUniqueID={39B24983-D827-4C7C-8782-029410E9C146} ScanAgent 8/10/2016 1:24:01 AM
*****ScanByUpdates request received with ForceReScan=0, ScanOptions=0x00000008, WSUSLocationTimeout = 604800 ScanAgent
ScanAgent then checks the update source and Time-To-Live (TTL) settings for the last scan results and submits a request for WSUS server location, then LocationService retrieves the WSUS location from the Management Point and returns the URL and the server name, as seen here in ScanAgent.log :
ScanJob({DCB47C9A-3D45-4495-8116-5EE9E0F3B4D2}): - - - - - -Locations requested for ScanJobID={DCB47C9A-3D45-4495-8116-5EE9E0F3B4D2} (LocationRequestID={6CBEFDD4-7390-4A41-AA4D-4D3F8B72111F}), will process the scan request once locations are available. ScanAgent 8/10/2016 1:24:03 AM
*****WSUSLocationUpdate received for location request guid={6CBEFDD4-7390-4A41-AA4D-4D3F8B72111F} ScanAgent
Next, the Windows Update scan is initiated and we see the following in ScanAgent.log :
*****ScanByUpdates request received with ForceReScan=0, ScanOptions=0x00000008, WSUSLocationTimeout = 604800 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
- - -Evaluating Update Status... ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:4d52d21e-e4a1-4043-bcda-69a696b2b257 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:4d52d21e-e4a1-4043-bcda-69a696b2b257 ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:a12fff7b-aefc-4815-ab2e-0048ada4ea9e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:a12fff7b-aefc-4815-ab2e-0048ada4ea9e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:c071152f-3697-44f4-b77c-bf07519dd63e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:c071152f-3697-44f4-b77c-bf07519dd63e ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Found CategoryID of :0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:e6561a3e-2ee6-48e4-8770-78068771cfcb ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
CScanAgent::ScanByUpdates - Found UpdateClassification 0fa1201d-4330-4fa8-8ae9-b877473b6441 for Update:e6561a3e-2ee6-48e4-8770-78068771cfcb ScanAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
State messages are created for each software update that changed in compliance state, then state messages are sent to the Management Point as seen in StateMessage.log :
Adding message with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 to WMI StateMessage 8/10/2016 1:25:53 AM 5148 (0x141C)
State message(State ID : 2) with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 has been recorded for SYSTEM StateMessage 8/10/2016 1:25:53 AM 5148 (0x141C)
Successfully forwarded State Messages to the MP StateMessage 5148 (0x141C)
We also see entries similar to the following in WUAHandler.log :
Its a WSUS Update Source type ({39B24983-D827-4C7C-8782-029410E9C146}), adding it. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Existing WUA Managed server was already set ( http://FC-CM01.fourthcoffee.local:8530) , skipping Group Policy registration. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Added Update Source ({39B24983-D827-4C7C-8782-029410E9C146}) of content type: 2 WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Scan results will include superseded updates only when they are superseded by service packs and definition updates. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Search Criteria is (DeploymentAction=* AND Type='Software') OR (DeploymentAction=* AND Type='Driver') WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Async searching of updates using WUAgent started. WUAHandler 8/10/2016 1:24:42 AM 7544 (0x1D78)
Async searching completed. WUAHandler 8/10/2016 1:25:52 AM 1308 (0x051C)
Successfully completed scan. WUAHandler 8/10/2016 1:25:52 AM 5148 (0x141C)
Installation
When a client computer in the target collection for the deployment receives the machine policy, machine policy including new or changed deployment assignment policy is downloaded. UpdatesDeployment.log receives modification event and triggers evaluation and installation process, as shown here:
Assignment {b8cf0a9f-3b46-4ce7-9712-b281aa88b953} has total CI = 16 UpdatesDeploymentAgent 8/10/2016 1:24:02 AM 7956 (0x1F14)
OnPolicyModify for assignment ({b8cf0a9f-3b46-4ce7-9712-b281aa88b953})... UpdatesDeploymentAgent 8/10/2016 1:24:02 AM 7956 (0x1F14)
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Name (Cumulative Update for Windows 10 Version 1511 (KB3176493)) ArticleID (3176493) added to the targeted list of deployment ({b8cf0a9f-3b46-4ce7-9712-b281aa88b953}) UpdatesDeploymentAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
Raising client SDK event for class CCM_SoftwareUpdate, instance CCM_SoftwareUpdate.UpdateID="Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257", actionType 11l, value NULL, user NULL, session 4294967295l, level 0l, verbosity 30l UpdatesDeploymentAgent 8/10/2016 1:26:41 AM 5148 (0x141C)
UpdatesStore will check the status of each update and look for the source, then CIDownloader determines applicability for each update. This is shown in UpdateStore.log :
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Missing, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 1:25:53 AM 4316 (0x10DC)
Querying update status of 2 updates. UpdatesStore 8/10/2016 3:10:47 AM 6232 (0x1858)
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Missing, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 3:26:49 AM 6232 (0x1858)
Queried Update (4d52d21e-e4a1-4043-bcda-69a696b2b257): Status=Installed, Title=Cumulative Update for Windows 10 Version 1511 (KB3176493), BulletinID=MS16-095, QNumbers=3176493, LocaleID=, ProductID=0fa1201d-4330-4fa8-8ae9-b877473b6441, UpdateClassification = 0fa1201d-4330-4fa8-8ae9-b877473b6441, ExcludeForStateReporting=FALSE. UpdatesStore 8/10/2016 5:08:07 AM 3628 (0x0E2C)
UpdatesHandler then retrieves download settings and software update relationships, then calls to download content.
Entries similar to the following appear in UpdatesHanlder.log :
Bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) is requesting download from child updates for action (INSTALL) UpdatesHandler 8/10/2016 1:26:41 AM 7556 (0x1D84)
StateCore - bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) state changed from (WAIT_CONTENTS) to (EXECUTE_READY) as child update state changed UpdatesHandler 8/10/2016 3:10:43 AM 6548 (0x1994)
Bundle update (4d52d21e-e4a1-4043-bcda-69a696b2b257) is requesting download from child updates for action (INSTALL) UpdatesHandler 8/10/2016 3:10:48 AM 4432 (0x1150)
Entries similar to the following appear in WUAHandler.log :
Going to search using WSUS update source. WUAHandler 8/10/2016 3:10:49 AM 3688 (0x0E68)
Synchronous searching of all updates started... WUAHandler 8/10/2016 3:10:49 AM 3688 (0x0E68)
Successfully completed synchronous searching of updates. WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
1. Update: 4d52d21e-e4a1-4043-bcda-69a696b2b257, 205 BundledUpdates: 1 WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
Update: a12fff7b-aefc-4815-ab2e-0048ada4ea9e, 200 BundledUpdates: 0 WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
1. Update (Missing): Cumulative Update for Windows 10 Version 1511 (KB3176493) (4d52d21e-e4a1-4043-bcda-69a696b2b257, 205) WUAHandler 8/10/2016 3:11:00 AM 3688 (0x0E68)
Async installation of updates started. WUAHandler 8/10/2016 3:12:58 AM 3688 (0x0E68)
Update 1 (4d52d21e-e4a1-4043-bcda-69a696b2b257) finished installing (0x00000000), Reboot Required? Yes WUAHandler 8/10/2016 3:26:35 AM 4708 (0x1264)
Async install completed. WUAHandler 8/10/2016 3:26:46 AM 5660 (0x161C)
Installation of updates completed. WUAHandler 8/10/2016 3:26:46 AM 6232 (0x1858)
Then we get the content location and the following is logged in LocationService.log :
Calling back with the following distribution points LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Distribution Point=' http://FC-CM01.fourthcoffee.local/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e', Locality='LOCAL', DPType='SERVER', Version='8325', Capabilities='<Capabilities SchemaVersion="1.0"><Property Name="SSLState" Value="0"/></Capabilities>', Signature=' http://FC-CM01.fourthcoffee.local/SMS_DP_SMSSIG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e.1.tar', ForestTrust='TRUE', LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Filtering locations for request {E68DF60D-00D0-4330-9ECE-8742B48CB801}. LocationServices 8/10/2016 3:09:02 AM 5648 (0x1610)
Then software update content is downloaded to the cache and the following is logged in DataTransferService.log :
UpdateURLWithTransportSettings(): OLD URL - http://FC-CM01.fourthcoffee.local/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
UpdateURLWithTransportSettings(): NEW URL - http://FC-CM01.fourthcoffee.local:80/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
DTSJob {252AF5CA-A261-49FA-82DB-50556214AEAC} created to download from ' http://FC-CM01.fourthcoffee.local:80/SMS_DP_SMSPKG $/a12fff7b-aefc-4815-ab2e-0048ada4ea9e' to 'C:\Windows\ccmcache\1b'. DataTransferService 8/10/2016 3:09:02 AM 5648 (0x1610)
DTSJob {252AF5CA-A261-49FA-82DB-50556214AEAC} in state 'DownloadingManifest'. DataTransferService 8/10/2016 3:09:02 AM 6548 (0x1994)
GET: Host=FC-CM01.fourthcoffee.local, Path=/SMS_DP_SMSPKG$/a12fff7b-aefc-4815-ab2e-0048ada4ea9e, Port=80, Protocol=http, Flags=133, Options=224 DataTransferService 8/10/2016 3:09:02 AM 4320 (0x10E0)
UpdatesDeploymentAgent then raises a state message (download complete) and calls WUAHandler to handle the software update installation via WUA. You can see this via the following entries in UpdatesDeployment.log :
ApplyCIs - JobId = {301925A8-283F-42AE-95F0-272A10359929} UpdatesDeploymentAgent 8/10/2016 3:10:47 AM 4432 (0x1150)
…...
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Progress: Status = ciStateInstalling, PercentComplete = 10, DownloadSize = 0, Result = 0x0 UpdatesDeploymentAgent 8/10/2016 3:19:31 AM 4432 (0x1150)
Update (Site_39B24983-D827-4C7C-8782-029410E9C146/SUM_4d52d21e-e4a1-4043-bcda-69a696b2b257) Progress: Status = ciStateInstalling, PercentComplete = 100, DownloadSize = 0, Result = 0x0 UpdatesDeploymentAgent 8/10/2016 3:24:54 AM 3688 (0x0E68)
CUpdatesJob({301925A8-283F-42AE-95F0-272A10359929}): Job completion received. UpdatesDeploymentAgent 8/10/2016 3:26:50 AM 4320 (0x10E0)
CUpdatesJob({301925A8-283F-42AE-95F0-272A10359929}): Delete job from WMI UpdatesDeploymentAgent 8/10/2016 3:26:50 AM 4320 (0x10E0)
WUA then installs the updates and we see the following in CBS.log :
2016-08-10 03:13:02, Info CBS Opened cabinet package, package directory: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\, sandbox location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\, cabinet location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\Windows10.0-KB3176493-x86.cab, manifest location: \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\update.mum
2016-08-10 03:14:36, Info CBS Extracting all files from cabinet \\?\C:\WINDOWS\SoftwareDistribution\Download\b0e4281cd82e8b66165a25b8a4ae6648\inst\Cab_1_for_KB3176493.cab
Next, state messages are created for each software update that changed in compliance state, and these state messages are sent to the management point as seen in StateMessage.log :
State message(State ID : 3) with TopicType 500 and TopicId 4d52d21e-e4a1-4043-bcda-69a696b2b257 has been recorded for SYSTEM StateMessage 8/10/2016 5:08:07 AM 3784 (0x0EC8)
At this point the updates are installed and the hierarchy is updated.
More Information
For more information about state message and ID, please see the table below.
Ref: State Messages in Configuration Manager 2007
For more information on Software Updates, see Introduction to Software Updates in Configuration Manager
Ibrahim Aladwan , Support Engineer
Microsoft System Center Configuration Manager
Updated Oct 17, 2018
Version 2.0
J.C. Hornbeck
Microsoft
Microsoft
