How to track an installation through client log-files

If you ever need to track a software deployment on a client, you’ll have a bunch of log-files where you find answers. During a software deployment (and download) the following client log-files is invoked in the following order:

  1. AppDiscovery.log
  2. AppIntentEval.log
  3. AppDiscovery.log
  4. CAS.log
  5. ContentTransferManager.log
  6. DataTransferService.log
  7. ContentTransferManager.log
  8. CAS.log
  9. AppEnforce.log
  10. AppIntentEval.log

The log-files can be found on the client C:\Windows\CCM\Logs. When tracking the deployment, two identifiers are needed; the unique ID of the applications Deployment Type, and the ContentID. The first can be found up front, while the latter can be found in AppDiscovery.log.

 

Credit due: Adam Pazik wrote a great article which inspired to this post.

How to get the Unique ID used for tracking (the long version)

When tracking an installation, the unique ID of the applications deployment type is used. If you just want to get that one, skip to the end of this section. If you want to know more, read on..

Everything in ConfigMgr has a unique ID, and the same goes for both Applications and their Deployment Types. The unique ID for Applications (CI_UniqueID) looks like this:

ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/Application_f9d92c28-d4b6-40f6-bf9e-9c50a0db9856/4

The ScopeId_ part is the Authoring Scope, which is unique to the site server, the Application_ part is unique to the application, and finally the “/4” indicates that this is the fourth revision of the application (each time you change something in the Console, the revision increases). If you are interested, you can determine the Authoring Scope using this PowerShell code:


$Site = Invoke-WmiMethod -Namespace Root\SMS\Site_MTL -ComputerName CM2012 -Path SMS_Identification -name GetSiteID
$Site.SiteID

This would produce “{9D808D91-5ABE-48AC-908B-ADA69B7208CE}” in my test environment, which you can see matches the ScopeId part of the applications Unique ID.

Similar the applications deployment type also has an unique ID:

ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5

The same goes for the ScopeId_, DeploymentType_ and revision part. If you want to retrieve all Unique ID’s for an applications deployment type (say “Reader 11.0.12”), you can use the following code:

$APPQuery = Get-WmiObject -Namespace Root\SMS\Site_MTL -Class SMS_DeploymentType -ComputerName CM2012 -Filter "LocalizedDisplayName='Reader 11.0.12'"
$APPQuery.CI_UniqueID

This will produce the following output:

ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/1
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/2
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/3
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/4
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5

Now, when tracking an installation the unique ID of the deployment type is used, but without the revision part (eg ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e). If you want to retrieve just that, you can use the ModelName property of SMS_DeploymentType instead of CI_UniqueID. The ModelName is actually the desired configuration management model name for the configuration item, but it gives just what we need. Change the previous PowerShell code slightly, and you get:

$APPQuery = Get-WmiObject -Namespace Root\SMS\Site_MTL -Class SMS_DeploymentType -ComputerName CM2012 -Filter "LocalizedDisplayName='Reader 11.0.12'"
$APPQuery.ModelName

This gives us the unique part ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e we can use to track the installation in the ConfigMgr client log files.

 

 

 

Time to follow the white rabbit…

In the example shown here, an application has been deployed to a collection in which the computer is a member. Now, from the top down:

 

PolicyAgent.log: Tell the client that it have stuff to do

First the client needs to know that it has new application assignments. The client determines this during its machine policy cycle, which runs each 60 minute by default. You can also trigger this by running the Machine Policy Retrieval & Evaluation Cycle from the ConfigMgr Client, or from the ConfigMgr Console using Client Notification > Download Computer Policy. You can verify that the machine policy is started using PolicyAgent.log:

Requesting Machine policy from authority 'SMS:MTL'

And further down the line, you can see it is told to get the policy for the application:

Initializing download of policy 'CCM_Policy_Policy5.PolicyID="ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/Application_f9d92c28-d4b6-40f6-bf9e-9c50a0db9856/CA",PolicySource="SMS:MTL",PolicyVersion="5.00"' from 'http://CM02.METAL.LOCAL/SMS_MP/.sms_pol?ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/Application_f9d92c28-d4b6-40f6-bf9e-9c50a0db9856/CA.SHA256:E8EA1B1EF90C3985CEF6B76C212F06ECC0A716B93E48ABF50FC8159D5C526206'

 

AppDiscovery.log: Is the application already installed?

All applications (not packages) in ConfigMgr 2012 contains detection methods, to determine if the application is installed. The detection method(s) run before and after an application is installed. This can be tracked in the AppDiscovery.log file, using the Deployment Type’s Unique ID. You can notice that AppDiscovery is Performing detection of app deployment type Reader 11.0.12 and Did not detection app deployment type Reader 11.0.12 (which is tracked using the unique id).


Entering ExecQueryAsync for query "select * from CCM_AppDeliveryType where (AppDeliveryTypeId = "ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e" AND Revision = 5)"	AppDiscovery	14-08-2015 06:05:06	2912 (0x0B60)
    Performing detection of app deployment type Reader 11.0.12(ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, revision 5) for system.	AppDiscovery	14-08-2015 06:05:06	2912 (0x0B60)
+++ Application not discovered. [AppDT Id: ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, Revision: 5]	AppDiscovery	14-08-2015 06:05:06	2912 (0x0B60)
+++ Did not detect app deployment type Reader 11.0.12(ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, revision 5) for system.	AppDiscovery	14-08-2015 06:05:06	2912 (0x0B60)

A note on the side: If the detection method does not work properly, and the ConfigMgr client was unable to verify that the application was properly installed (using the detection method), you will get a return code of 0x87D00324 in Software Center on the client.

Also, you will see that if an application is deployed to a computer, which already has the application installed (as determined by the detection method), the installation files will never be downloaded to the computer. This is a nice consequence of the Application Model in ConfigMgr 2012.

 

AppIntentEval.log: Does the application have any dependencies?

AppIntentEval.log now takes over, and determines if there are any required dependencies to the application:

No dependencies for DeploymentType ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5.	AppIntentEval	14-08-2015 06:05:06	2896 (0x0B50)
* Evaluating Application policies for Machine	AppIntentEval	14-08-2015 06:05:06	2896 (0x0B50)
DT id = ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/RequiredApplication_f9d92c28-d4b6-40f6-bf9e-9c50a0db9856/5, technology = Script	AppIntentEval	14-08-2015 06:05:06	2896 (0x0B50)
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5 :- Current State = NotInstalled, Applicability = Applicable, ResolvedState = Installed, ConfigureState = NotNeeded, Title = Reader 11.0.12	AppIntentEval	14-08-2015 06:05:06	2896 (0x0B50)

 

AppDiscovery.log: Lets continue and get the content

Back in AppDiscovery.log we see that the installation should continue, and which content should be used for the installation (the Content Id):

   ActionType - Install will use Content Id: Content_049f55eb-9172-4b84-890d-332a3a735a59 + Content Version: 1 for AppDT "Reader 11.0.12" [ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e], Revision - 5	AppDiscovery	14-08-2015 06:05:06	2912 (0x0B60)

The Content Id Content_049f55eb-9172-4b84-890d-332a3a735a59 is now used to track the content download.

 

CAS.log: Do the client already have the content?

The CAS (Content Access Service), which maintains the local package cache, checks if it already has the content. In this case the content is not present in the cache:

**** Received request for content Content_049f55eb-9172-4b84-890d-332a3a735a59.1, size(KB) 195144, under context System with priority Medium.	ContentAccess	14-08-2015 06:05:06	2896 (0x0B50)
CacheManager: There are currently 0 bytes used for cached content items (0 total, 0 active, 0 tombstoned, 0 expired).	ContentAccess	14-08-2015 06:05:06	2896 (0x0B50)
...
Location update from CTM for content Content_049f55eb-9172-4b84-890d-332a3a735a59.1 and request {38877591-5991-4383-A010-FE2D4818BAE1}	ContentAccess	14-08-2015 06:05:07	2200 (0x0898)
   Download location found 0 - http://DP01.METAL.LOCAL/SMS_DP_SMSPKG$/Content_049f55eb-9172-4b84-890d-332a3a735a59.1	ContentAccess	14-08-2015 06:05:07	2200 (0x0898)
   Download request only, ignoring location update	ContentAccess	14-08-2015 06:05:07	2200 (0x0898)
Download started for content Content_049f55eb-9172-4b84-890d-332a3a735a59.1	ContentAccess	14-08-2015 06:05:07	2200 (0x0898)

If the content already was in the client cache, CAS.log would write the following instead:

**** Received request for content Content_049f55eb-9172-4b84-890d-332a3a735a59.1, size(KB) 195144, under context System with priority Medium.	ContentAccess	14-08-2015 05:05:58	2776 (0x0AD8)
Saved Content ID Mapping Content_049f55eb-9172-4b84-890d-332a3a735a59.1, C:\WINDOWS\ccmcache\2	ContentAccess	14-08-2015 05:05:58	2776 (0x0AD8)
Content for Content_049f55eb-9172-4b84-890d-332a3a735a59.1 was found in cache, content size is 195144K	ContentAccess	14-08-2015 05:05:58	2776 (0x0AD8)

CAS.log now instructs ContentTransferManager.log to initiate the download.

 

ContentTransferManager.log: Who should download the content?

ConfigMgr 2012 normally uses BITS to download content from the distribution point. However, ConfigMgr 2012 also supports Alternative Content Providers (such as 1E Nomad) to handle the content download. ContentTransferManager.log is the one who determines how the content should be downloaded. In this case, the download request is handed over to DataTransferService.log:

Created and Sent Location Request '{222EE95B-3BD8-48C4-8AF1-1A8C640CF361}' for package Content_049f55eb-9172-4b84-890d-332a3a735a59	ContentTransferManager	14-08-2015 06:05:07	2992 (0x0BB0)

 

DataTransferService.log: Downloading the content

In DataTransferService.log it is possible to track the complete download process.

DTSJob {42D941B4-602C-497C-A0C8-92A7A597F882} created to download from 'http://DP01.METAL.LOCAL:80/SMS_DP_SMSPKG$/Content_049f55eb-9172-4b84-890d-332a3a735a59.1' to 'C:\WINDOWS\ccmcache\9'.	DataTransferService	14-08-2015 06:05:07	1020 (0x03FC)
...
DTSJob {416331FB-E02A-42EA-91ED-21273B387EB4} in state 'DownloadingData'.	DataTransferService	14-08-2015 06:05:14	2200 (0x0898)
DTSJob {42D941B4-602C-497C-A0C8-92A7A597F882} in state 'RetrievedData'.	DataTransferService	14-08-2015 06:05:35	1388 (0x056C)
DTSJob {42D941B4-602C-497C-A0C8-92A7A597F882} successfully completed download.	DataTransferService	14-08-2015 06:05:35	1388 (0x056C)

 

ContentTransferManager.log: Notified of download complete

Following the chain back to the surface, we see that ContentTransferManager.log is notified:

CTM job {7FDCA2EB-9E5E-4C8E-B766-BF6D9483C22A} successfully processed download completion.	ContentTransferManager	14-08-2015 06:05:36	2200 (0x0898)

 

CAS.log: Notified of download complete, again

Which in turn notifies CAS.log:

Download completed for content Content_049f55eb-9172-4b84-890d-332a3a735a59.1 under context System	ContentAccess	14-08-2015 06:05:36	2200 (0x0898)

 

AppEnforce.log: Installing the application

Now we have the installation files, it is time to start the installation. AppEnforce.log reveals the details of this:

+++ Starting Install enforcement for App DT "Reader 11.0.12" ApplicationDeliveryType - ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, Revision - 5, ContentPath - C:\WINDOWS\ccmcache\9, Execution Context - System	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    A user is logged on to the system.	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Performing detection of app deployment type Reader 11.0.12(ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, revision 5) for system.	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
+++ Application not discovered. [AppDT Id: ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, Revision: 5]	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    App enforcement environment:
	Context: Machine
	Command line: "setup.exe"
	Allow user interaction: No
	UI mode: 1
	User token: null
	Session Id: 4294967295
	Content path: C:\WINDOWS\ccmcache\9
	Working directory: 	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Prepared working directory: C:\WINDOWS\ccmcache\9	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Prepared command line: "C:\WINDOWS\ccmcache\9\setup.exe" 	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Executing Command line: "C:\WINDOWS\ccmcache\9\setup.exe" with system context	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Working directory C:\WINDOWS\ccmcache\9	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Post install behavior is NoAction	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Waiting for process 2384 to finish.  Timeout = 120 minutes.	AppEnforce	14-08-2015 06:05:39	2912 (0x0B60)
    Process 2384 terminated with exitcode: 0	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)
    Looking for exit code 0 in exit codes table...	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)
    No action needed after successful enforcement	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)
    Performing detection of app deployment type Reader 11.0.12(ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, revision 5) for system.	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)
+++ Discovered application [AppDT Id: ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e, Revision: 5]	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)
++++++ App enforcement completed (49 seconds) for App DT "Reader 11.0.12" [ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e], Revision: 5, User SID: ] ++++++	AppEnforce	14-08-2015 06:06:28	2912 (0x0B60)

Here you can see all the good installation stuff, as well as the second check using the detection method of the Application.

 

AppIntentEval.log: Final check

Finally, the AppIntentEval.log reveals that the application is installed (Current State = Installed):

No dependencies for DeploymentType ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5.	AppIntentEval	14-08-2015 06:06:30	1020 (0x03FC)
* Evaluating Application policies for Machine	AppIntentEval	14-08-2015 06:06:30	1020 (0x03FC)
ScopeId_9D808D91-5ABE-48AC-908B-ADA69B7208CE/DeploymentType_fbfe859a-4810-4ba2-b86d-2013c62f586e/5 :- Current State = Installed, Applicability = Applicable, ResolvedState = Installed, ConfigureState = NotNeeded, Title = Reader 11.0.12	AppIntentEval	14-08-2015 06:06:30	1020 (0x03FC)

This concludes this small walk through of the client log-files used when deploying software.

Now, what would be really cool is that if one wrote a PowerShell script to track the files log-files! Perhaps some day..

Advertisements

8 thoughts on “How to track an installation through client log-files

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out /  Change )

Google+ photo

You are commenting using your Google+ account. Log Out /  Change )

Twitter picture

You are commenting using your Twitter account. Log Out /  Change )

Facebook photo

You are commenting using your Facebook account. Log Out /  Change )

Connecting to %s