Troubleshoot the Install Application task sequence in Microsoft Configuration Manager

Overview of the Install Application task

The Install Application task process outlined here covers a single application installtask, although it can also be used for troubleshooting the installation of multipleapplications based on a list.

When the Install Application process runs, the application checks the applicability of therequirement rules and detection method on the deployment types of theapplication. Based on the results of this check, the application installs theapplicable deployment type. If a deployment type contains dependencies, the dependent deployment type is evaluated and installed as part of the Install Application step.

For more information about the Install Application task sequence process please review this TechNet article.

Task Sequence Manager parses the task sequence XML and begins the Install Application task

Application installations in a task sequence have a lot incommon with application installations outside of a task sequence, in that theyboth leverage Configuration manager compliance settings.However, they do not function exactly the same as there are more components involved due to the nature of running during a task sequence.

As the task sequence progresses, it maintains the status oftasks and the associated execution status using task sequence environmentvariables (see https://technet.microsoft.com/en-us/library/hh273375.aspx for more information). These built in variables provide information about theenvironment where the task sequence is running, and their values for thesevariables are available throughout the whole task sequence. In the case of an Install Application task, these built invariables are initialized before the process runs in the task sequence.

Task Sequence Manager sets global environment variables for the next instruction, _SMSTSCurrentActionName to Install Application and _SMSTSNexInstructionPointer to the Instruction Pointer assigned to this task. This can be observed in the following entries in SMSTS.log:

01-13-2016 17:56:35.510   TSManager    2176 (0x880)    Start executing an instruction. Instructionname: Install Application. Instruction pointer: 32 01-13-2016 17:56:35.510   TSManager    2176 (0x880)    Set a global environment variable_SMSTSCurrentActionName=Install Application 01-13-2016 17:56:35.510   TSManager    2176 (0x880)    Set a global environment variable_SMSTSNextInstructionPointer=32 

TSManager then saves the execution state of the task sequenceand the environment (TSEnv.dat) to the local hard disk as seen here in SMSTS.log:

01-13-2016 17:56:35.510    TSManager    2176 (0x880)    Successfully save execution state and environment to local hard disk 

Task Sequence Manager starts the execution of the next instruction in the sequence, based on the execution history of the previous instruction and the next instruction pointer:

01-13-2016 17:56:35.510   TSManager    2176 (0x880)    Start executing an instruction. Instructionname: Install Application. Instruction pointer: 32 

Task Sequence Manager then sets local default variables for applications:

01-13-201617:56:35.510    TSManager    2176 (0x880)    Set a local default variableOSDApp0Description01-13-201617:56:35.510    TSManager    2176 (0x880)    Set a local default variableOSDApp0DisplayName 01-13-201617:56:35.510    TSManager    2176 (0x880)    Set a local default variable OSDApp0Name 01-13-201617:56:35.510    TSManager    2176 (0x880)    Set a local default variable OSDAppCount 01-13-201617:56:35.525    TSManager    2176 (0x880)    Set a global environment variable_SMSTSLogPath=C:\WINDOWS\CCM\Logs\SMSTSLog

01-13-2016 17:56:35.525   TSManager    2176 (0x880)    Executing command line: smsappinstall.exe/app:ScopeId_GUID/Application_GUID/basevar: /continueOnError:False 

During this step, the Install Application component evaluates the task sequence policy and stores it in WMI. The application checks the applicability of the requirement rules and detection method on the deployment types of the application. This is done using CIStore and CIStateStore to evaluate the applicability and state of the Configuration Items and the Configuration Data Content associated with the application and deployment Type. The result is that the CI's will be marked for download.

01-13-2016 17:56:35.572    InstallApplication    1608 (0x648)    Application Names: 01-13-2016 17:56:35.572    InstallApplication    1608 (0x648)    'ScopeId_GUID/Application_GUID' 

01-13-2016 17:56:35.666    InstallApplication    1608 (0x648)    Setting TSEnv variable 'SMSTSAppPolicyEvaluationJobID__ScopeId_GUID/Application_GUID'=''01-13-2016 17:56:35.666    InstallApplication    1608 (0x648)    Setting TSEnv variable 'SMSTSInstallApplicationJobID__ScopeId_GUID/Application_GUID'=' 

01-13-2016 17:56:35.666    InstallApplication    1608 (0x648)    Retrieving value from TSEnv for '_SMSTSPolicy_ScopeId_GUID/Application_GUID

01-13-2016 17:56:35.666    InstallApplication    1608 (0x648)    Found App policy modelname:ScopeId_GUID/RequiredApplication_GUID and CIversion:10 

01-13-2016 17:56:35.666    InstallApplication    1608 (0x648)    Found App policy modelname:ScopeId_GUID/RequiredApplication_GUID and CIversion:10 01-13-2016 17:56:35.682    InstallApplication    1608 (0x648)    ::DecompressBuffer(65536) 01-13-2016 17:56:35.682    InstallApplication    1608 (0x648)    Decompression (zlib) succeeded: original size 145382, uncompressed size 1238794. 

01-13-2016 17:56:36.119    InstallApplication    1608 (0x648)    Locked ActualConfig successfully 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    New/Changed ActualConfig policy instance(s) : 6 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [1] Added/updated setting 'ccm_applicationciassignment:assignmentid=dep-meh20009-scopeid_GUID/application_GUID'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [2] Added/updated setting 'ccm_civersioninfo:modelname=scopeid_GUID/application_GUID:version=10'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [3] Added/updated setting 'ccm_civersioninfo:modelname=scopeid_GUID/deploymenttype_GUID:version=6'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [4] Added/updated setting 'ccm_civersioninfo:modelname=scopeid_GUID/requiredapplication_GUID:version=10'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [5] Added/updated setting 'ccm_civersioninfo:modelname=windows/all_windows_client_server:version=1'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    [6] Added/updated setting 'ccm_scheduler_scheduledmessage:scheduledmessageid=dep-meh20009-scopeid_GUID/application_GUID'. 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    Unlocked ActualConfig successfully 01-13-2016 17:56:36.150    InstallApplication    1608 (0x648)    Raising event: instance of CCM_PolicyAgent_SettingsEvaluationComplete { ClientID = "GUID:ClientGUID"; DateTime = "20160113225636.150000+000"; PolicyNamespace = "\\\\.\\root\\ccm\\policy\\machine\\actualconfig"; ProcessID = 1392; ThreadID = 1608; }; 

01-13-2016 17:56:36.150    PolicyAgentProvider    2424 (0x978)    [000000B205C423A8] 1 settings change(s) detected. 01-13-2016 17:56:36.182    PolicyAgentProvider    2424 (0x978)    [000000B205C423A8] Queued worker to process these 1 settings change(s) 01-13-2016 17:56:36.182    PolicyAgentProvider    2420 (0x974)    --- Processing 1 settings change(s). 01-13-2016 17:56:36.182    PolicyAgentProvider    2420 (0x974)    --- [1] __InstanceCreationEvent settings change on object CCM_ApplicationCIAssignment.AssignmentID="DEP-MEH20009-ScopeId_GUID/Application_GUID". 01-13-2016 17:56:36.182    PolicyAgentProvider    2420 (0x974)    --- Begin Indicating 1 settings change(s). 01-13-2016 17:56:36.182    PolicyAgentProvider    2420 (0x974)    --- Completed Indicating 1 settings change(s). 

01-13-2016 17:56:36.197   DCMAgent    2608 (0xa30)    DCMAgent::ProcessAssignmentChange. 

CIStore.log:

01-13-2016 17:56:36.260   CIStore    2608 (0xa30)   CCIStore::ProcessCITargetEvent - CIScopeId_GUID/Application_GUID:10 will be targeted for SYSTEM 01-13-2016 17:56:36.275   CIStore    2608 (0xa30)   CCIStore::ProcessCITargetEvent - CI ScopeId_GUID/DeploymentType_GUID:6 will be targeted for SYSTEM 

01-13-2016 17:56:36.275    CIStore    2608 (0xa30)    CCIStoreTargetedCIDownloader::AddCI - CI Modelname:ScopeId_GUID/Application_GUID Version:10 has been added for download 

01-13-2016 17:56:36.322    CIStateStore    2608 (0xa30)    CCIStateTransition::ExtractStateDetails - CI ModelName ScopeId_GUID/DeploymentType_GUID, version 6 not found in store. 

01-13-2016 17:56:36.369    CIStore    2608 (0xa30)    CCIStoreTargetedCIDownloader::AddCI - CI Modelname:ScopeId_GUID/DeploymentType_GUID Version:6 has been added for download

In the previous step, the CIs were marked for download. The DCM agent will now utilize CI Agent to begin acquiring the Configuration Items and Configuration Data Content (SDM package) from the database. This includes information such as Application Properties, Application Manifest, Deployment Type Properties, Deployment Type Manifest, Application Intent Policies for Compliance, etc.

• CI Agent
• CI Downloader
• CIStore
• Data Transfer Service
• Content Transfer Manager
• All of this information is requested from the database via the management point and the requests and responses can be monitored via the MP_GetSDMPackage.log file.
• Full Order of MP_GetSDMDocument execution/Data Transfer Service download for each App Install task:

1. App PROPERTIES - Results have basic App CI info. Name only.
2. App MANIFEST - links Policy Platform CI Documents with the Application CI.
3. App Intent Policy - Desired State of the Application, required.
4. App MANIFEST again. Note the different HASH. This time the results have extended info, WMI namespaces for WMI namespaces for the CI Manifests, App DT CI References.
5. App PROPERTIES again. Note the different HASH. This time the results include, extended/custom PROPERITES, Publisher, release date, icons, etc.
6. App DT PROPERTIES. Results include Description, estimated install time, post install behavior, etc.
7. App DT MANIFEST results have extended info, WMI namespaces for the CI Manifests.
8. App policy, results include Policy Platform MOF to be compiled client side with Desired State, App Properties and App DT Properties.
9. App DT Policy is compressed. Unable to decompress.

1. DCM Agent job ID.
   DCMAgent.log: 

   01-13-201617:56:36.979    DCMAgent    1568(0x620)    CDCMAgentJobMgr::StartJob - Starting DCM Agent job{ID}

2. DCM Agent creates a job for CI Agent.
   DCMAgent.log: 

   01-13-2016 17:56:37.088    DCMAgent    2768 (0xad0)    DCMAgentJob({ID}): CDCMAgent::InitiateCIAgentJob - Starting CI Agent Job {E672EA3F-29D7-46E5-B05E-7D72DF2C50E0} for target: machine. Refer to this CI agent job ID in ciagent.log for more details 

3. CIDownloader creates a job.
   CIDownloader.log:

   01-13-2016 17:56:37.166    CIDownloader    2728 (0xaa8)    CIDownloaderJob({ID}): SetFailureCondition - Job will fail immediately on error

4. DCM Agent is tracking the progress via its own job.
   DCMAgent.log: 
    

   01-13-2016 17:56:37.182    DCMAgent    2768 (0xad0)    DCMAgentJob({ID}): CDCMAgentJob::HandleEvent(Event=NotifyProgress, CurrentState=Evaluating)

5. CIDownloader calculates the scope of the CI which initiates a check of the CI Store. 
   CIDownloader.log: 

   01-13-2016 17:56:37.182    CIDownloader    2728 (0xaa8)    [Calculate Scope] - Adding CI Modelname:ScopeId_GUID/RequiredApplication_GUID Version:10 to Scoped CIs List of root Modelname:ScopeId_GUID/RequiredApplication_GUID Version:10 

   CIStore.log:

   01-13-201617:56:37.182    CIStore    2728(0xaa8)    CCIStore::GetTargetedCIReference invoked for CIScopeId_GUID/RequiredApplication_GUID:10targeted to SYSTEM 

6. The CI is queried for in CI State Store and not found.
   CIStateStore.log: 

   01-13-201617:56:37.197    CIStateStore    2728(0xaa8)    CCIStateTransition::ExtractStateDetails - CIModelNameScopeId_GUID/RequiredApplication_GUID,version 10 not found in store. 

7. Since it is not found, it is then added to the CIDownloader job.
   CIDownloader.log: 

   01-13-201617:56:37.213    CIDownloader    2728(0xaa8)   CIDownloaderJob({ID}): CI with ModelNameScopeId_GUID/RequiredApplication_GUID,Version 10. Model:(null) added to job. 

8. CI Agent now starts the CIDownloader job to download the CI's.
   CIAgent.log: 
    

   01-13-201617:56:37.229    CIAgent    2728(0xaa8)    CIAgentJob({E672EA3F-29D7-46E5-B05E-7D72DF2C50E0}):Started CIDownloadJob({1B065017-7AC4-4729-B15D-6415BED35D0E}) 

9. The CIDownloader job transitions to the Downloading Packages phase and adds the source files for the CIs to the request. Note that at this point, Packages refers to the SDM package, not content (binaries).
   CIDownloader.log: 

   01-13-201617:56:37.229    CIDownloader    2728(0xaa8)   CIDownloaderJob({ID}): DownloadPackages  01-13-201617:56:37.229    CIDownloader    2728(0xaa8)    --Source file:.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/MANIFEST&Hash=HashString&Compression=zlib  01-13-201617:56:37.229    CIDownloader    2728(0xaa8)    --Source file:.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/PROPERTIES&Hash=HashString&Compression=zlib 

10. CIDownloader calls into Data Transfer Service to request the manifest and properties for the application as well as the Application Deployment Type.
    DataTransferService.log:

    01-13-201617:56:37.275    DataTransferService    2728(0xaa8)    Added(source=.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/PROPERTIES&Hash=HashString&Compression=zlib,dest={JobID}_2.zip)pair from manifest.  01-13-201617:56:37.275    DataTransferService    2728(0xaa8)    Added(source=.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/MANIFEST&Hash=HashString&Compression=zlib,dest={JobID}_1.zip)pair from manifest.

11. Data Transfer Service calls into the MP_GetSDMPacakge ISAPI on the management point, which in turn requests the SDM package information from the database by triggering a SQL stored procedure.
    SQL Profiler:

    exec MP_GetSdmDocument N'ScopeId_GUID/RequiredApplication_GUID/10/PROPERTIES',N'HashString',N'1',N'1'  exec MP_GetSdmDocument N'ScopeId_GUID/RequiredApplication_GUID/10/MANIFEST',N'HashString',N'1',N'1'

12. Data Transfer Service starts a BITS job and adds the path to the job once the response is received and begins downloading the data.
    DataTransferService.log: 

    01-13-201617:56:37.432    DataTransferService    2316(0x90c)    Starting BITS job'{ID}' for DTS job'{ID}' under user 'S-1-5-18'.  01-13-201617:56:37.479    DataTransferService    2316(0x90c)    BITSHelper: Full source path to be transferred = http://PS1.contoto.lab:80/SMS_MP/.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/PROPERTIES&Hash=HashString&Compression=zlib 01-13-201617:56:37.479    DataTransferService    2316(0x90c)    Adding to BITS job:{ID}_2.zip  01-13-201617:56:37.479    DataTransferService    2316(0x90c)    BITSHelper: Full source path to be transferred= http://PS1.contoto.lab:80/SMS_MP/.sms_dcm?Id&DocumentId=ScopeId_GUID/RequiredApplication_GUID/10/MANIFEST&Hash=HashString&Compression=zlib 56:37.479   DataTransferService    2316 (0x90c)    Adding toBITS job: {ID}_1.zip 

13. Monitor DataTransferService.log for the completion of the SDM package download and search for lines similar to below. 
    Configuration Item #1 

    01-13-2016 17:56:37.588    DataTransferService    2748 (0xabc)    Job: {ID}, Total Files: 2, Transferred Files: 2, Total Bytes: 1160, Transferred Bytes: 1160 01-13-2016 17:56:37.588    DataTransferService    2748 (0xabc)    DTSJob {ID} successfully completed download. 

    Configuration Item #2

    01-13-2016 17:56:37.791    DataTransferService    1568 (0x620)    Job: {ID}, Total Files: 3, Transferred Files: 3, Total Bytes: 2616, Transferred Bytes: 2616 01-13-2016 17:56:37.791    DataTransferService    1568 (0x620)    DTSJob {ID} successfully completed download. 

    Configuration Item #3 

    01-13-2016 17:56:37.994    DataTransferService    2748 (0xabc)    Job: {ID}, Total Files: 3, Transferred Files: 3, Total Bytes: 3216, Transferred Bytes: 3216 01-13-2016 17:56:37.994    DataTransferService    2748 (0xabc)    DTSJob {ID} successfully completed download. 

    Configuration Item #4 

    01-13-2016 17:56:38.104    DataTransferService    1568 (0x620)    Job: {ID}, Total Files: 1, Transferred Files: 1, Total Bytes: 4172, Transferred Bytes: 4172 01-13-2016 17:56:38.104    DataTransferService    1568 (0x620)    DTSJob {ID} successfully completed download. 

Once the Data Transfer Service job has completed downloading all of the CIs referenced by Application Install, CIDownloader will check the hash of the CIs, decompress them, and then persist them in CI Store. It will do this for each of the CIs associated with the application. 

01-13-2016 17:56:37.588    DataTransferService    2748 (0xabc)    Job: {ID}, Total Files: 2, Transferred Files: 2, Total Bytes: 1160, Transferred Bytes: 116001-13-2016 17:56:37.588    DataTransferService    2748 (0xabc)    DTSJob {ID} successfully completed download. 01-13-2016 17:56:37.604    DataTransferService    2316 (0x90c)    DTSJob {ID} in state 'NotifiedComplete'. 

01-13-2016 17:56:37.619    CIDownloader    2768 (0xad0)    ::DecompressFile(C:\WINDOWS\CCM\CIDownloader\Staging\}_1.zip,65536,C:\WINDOWS\CCM\CIDownloader\Staging\{JobID}_1.xml) 01-13-2016 17:56:37.619    CIDownloader    2768 (0xad0)    VerifyCIDocumentHash - Preparing to verify hash for CI document ScopeId_GUID/RequiredApplication_GUID/10/MANIFEST01-13-2016 17:56:37.619    CIDownloader    2768 (0xad0)    ::DecompressFile(C:\WINDOWS\CCM\CIDownloader\Staging\{JobID}_2.zip,65536,C:\WINDOWS\CCM\CIDownloader\Staging\{JobID}_2.xml) 01-13-2016 17:56:37.619    CIDownloader    2768 (0xad0)    VerifyCIDocumentHash - Preparing to verify hash for CI document ScopeId_GUID/RequiredApplication_GUID/10/PROPERTIES

01-13-2016 17:56:38.119    CIAgent    2768 (0xad0)    CIAgentJob({ID}): CAgentJob::NotifyComplete - CIDownloader callback 01-13-2016 17:56:38.119    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=PersistingCIModels) 01-13-2016 17:56:38.119    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): PersistCIModels  

01-13-2016 17:56:38.119    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions 01-13-2016 17:56:38.182    CIDownloader    2728 (0xaa8)    DCM::LanternUtils::StoreModelDocument 01-13-2016 17:56:38.385    CIDownloader    2728 (0xaa8)    DCM::LanternUtils::StoreModelDocument succeeded 01-13-2016 17:56:38.385    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions - Lantern model document compiled to WMI. 01-13-2016 17:56:38.463    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions - Creating file C:\WINDOWS\CCM\CIDownloader\DigestStore\321EC9594015C9F9E6780EB4FEC210A78BEC119CB44ADE46A94C5F5B26F47948.xml 01-13-2016 17:56:38.463    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions - Creating file C:\WINDOWS\CCM\CIDownloader\DigestStore\B7BE90F13A8B7B3BD870B8DC5D0DF3E8378137B385988C2037A5C94EF21E4BCB.xml 01-13-2016 17:56:38.463    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions - Dcm Digest persisted to CIDigestStore. 

01-13-2016 17:56:38.463    CIDownloader    2728 (0xaa8)    CCIDigestStore::PersistIntegratedCIDefinitions - Dcm Digest persisted to CIDigestStore. 01-13-2016 17:56:38.463    CIDownloader    2728 (0xaa8)    CCIDownloader::CompleteJob for job {ID}. 

01-13-2016 17:56:38.479    CIAgent    2728 (0xaa8)    CCIInfo::AddDepedentCI for ModelName: ScopeId_GUID/Application_GUID Version: 10 01-13-2016 17:56:38.479    CIStore    2728 (0xaa8)    CCIStore::GetCIEx - Requested CI ModelName ScopeId_GUID/Application_GUID, Version 10 returned from [Store] 01-13-2016 17:56:38.479    CIStore    2728 (0xaa8)    Found property (DisplayName) value but only with fallback to US English: ConfigMgr 2012 Toolkit R2 01-13-2016 17:56:38.510    CIAgent    2728 (0xaa8)    CCIInfo::AddDepedentCI for ModelName: ScopeId_GUID/DeploymentType_GUID Version: 6 01-13-2016 17:56:38.510    CIStore    2728 (0xaa8)    CCIStore::GetCIEx - Requested CI ModelName ScopeId_GUID/DeploymentType_GUID, Version 6 returned from [Store] 01-13-2016 17:56:38.510    CIStore    2728 (0xaa8)    Found property (DisplayName) value but only with fallback to default: ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file) 

All of the work of acquiring the necessary CIs and SDM package data has been downloaded at this point. CI Agent will invoke SDMMethod to bind the CIs to their Policy Platform/Lantern Policies stored in WMI (located at root\Microsoft\PolicyPlatform\Documents\Local), evaluate their applicability, and ultimately mark them as Available for Enforcement before cleaning up its jobs.

01-13-2016 17:56:38.510    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): TransitionState(From=PersistingCIModels, To=InvokingSdmMethod) for Event=Transition

01-13-2016 17:56:38.541    CIAgent    2316 (0x90c)    CIAgentJob({ID}): StartEnactment - CI - ScopeId_GUID/RequiredApplication_GUID 01-13-2016 17:56:38.541    CIAgent    2316 (0x90c)    CIAgentJob({ID}): Evaluation for CI 'ScopeId_GUID/RequiredApplication_GUID.10'is required. 

01-13-2016 17:56:38.541    CIAgent    2316 (0x90c)    CIAgentJob({ID}): Evaluation for CI 'ScopeId_GUID/RequiredApplication_GUID.10'is required. 01-13-2016 17:56:38.541    CIAgent    2316 (0x90c)    CIAgentJob({ID}): StartEnactment - Attempting to invoke Policy Platform Client 01-13-2016 17:56:38.885    CIAgent    2316 (0x90c)    DCM::LanternUtils::ScopeAndBindPolicies - [ScopedPolicies] ScopeId_GUID_Application_GUID_Platform_PolicyDocument 01-13-2016 17:56:38.885    CIAgent    2316 (0x90c)    DCM::LanternUtils::ScopeAndBindPolicies - [ScopedPolicies] ScopeId_GUID_Application_GUID_Configuration_PolicyDocument 

01-13-2016 17:56:38.885    CIAgent    2316 (0x90c)    DCM::LanternUtils::ScopeAndBindPolicies - [ScopedPolicies] ScopeId_GUID_DeploymentType_GUID_Discovery_PolicyDocument 01-13-2016 17:56:39.619    CIAgent    2768 (0xad0)    CIAgentJob({ID}): Invocation succeeded for policy platform job ID01-13-2016 17:56:39.619    CIAgent    2316 (0x90c)    Lantern job:ID succeeded. 01-13-2016 17:56:39.619    CIAgent    2768 (0xad0)    CIAgentJob({ID}): ReportMethodInvocation :: Enactment succeeded 

01-13-2016 17:56:39.963    CIAgent    2768 (0xad0)    CIAgentJob({ID}): TransitionState(From=StateDownloadingContents, To=StateEnforcingCIs) for Event=Transition 01-13-2016 17:56:39.963    CIAgent    2768 (0xad0)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=CITaskComplete, CurrentState=StateEnforcingCIs) 

01-13-2016 17:56:39.963    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=StateEnforcingCIs) 

01-13-2016 17:56:39.979    DCMAgent    1844 (0x734)    CAppMgmtSDK::GetEvaluationState ScopeId_GUID/RequiredApplication_GUID.10 = AvailableForEnforcement 

01-13-2016 17:56:40.057    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=StateEnforcementReporting) 

01-13-2016 17:56:40.072    CIAgent    2356 (0x934)    Internal Request to delete CIAgent job {ID} 

01-13-2016 17:56:40.088    DCMAgent    2728 (0xaa8)    DCMAgentJob({ID}): CDCMAgentJob::HandleEvent(Event=Transition, CurrentState=Success) 

01-13-2016 17:56:40.104    CIAgent    2356 (0x934)    CIAgentJob({ID}): Job complete. Exiting event pump. 

01-13-2016 17:56:40.104    DCMAgent    2728 (0xaa8)    CDCMAgentJobMgr::DeleteJob - Request to delete DCM Agent job {ID} 01-13-2016 17:56:40.135    DCMAgent    2728 (0xaa8)    DCMAgentJob({ID}): QueueDebug - Executing Event. 01-13-2016 17:56:40.104    DCMAgent    2728 (0xaa8)    Job complete. Exiting event pump.

Install Application will now call back into the SDK to install the application. This creates a new job for DCM Agent, which in turn creates a job for CI Agent and all of the components it uses. The same process will occur, where CI Agent utilizes the components to ensure that all the CIs have been downloaded, evaluated and persisted. The result of this step is that the content (binaries) for the Application Install process will be marked for download.

InstallApplication.log:

01-13-2016 17:56:40.119    InstallApplication    1608 (0x648)    Invoking App Management SDK to install application 01-13-2016 17:56:40.135    InstallApplication    1608 (0x648)    Installing application 'ScopeId_GUID/RequiredApplication_GUID' has started. Please refer to DCMAgent.log for the details on this job. JobID='{ID}' 

01-13-2016 17:56:40.135    DCMAgent    2356 (0x934)    DCMAgentJob({ID}): CDCMAgent::InitiateCIAgentJob - Starting CI Agent Job {ID} for target: machine. Refer to this CI agent job ID in ciagent.log for more details 

01-13-2016 17:56:40.135    CIAgent    2356 (0x934)    CIAgentJob({ID}): [LeakTest] AgentJob created 

01-13-2016 17:56:40.135    CIAgent    2768 (0xad0)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=WaitingForAssignedCI) 01-13-2016 17:56:40.135    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=DownloadCIs, CurrentState=WaitingForAssignedCI) 01-13-2016 17:56:40.135    CIAgent    2768 (0xad0)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=DownloadingCIs) 

 01-13-2016 17:56:40.135    CIDownloader    2768 (0xad0)    CIDownloaderJob({ID}): SetFailureCondition - Job will fail immediately on error 

01-13-2016 17:56:40.166    CIDownloader    2768 (0xad0)    CDownloadPayloadInfo::AddCI - CI with ModelName ScopeId_GUID/Application_GUID, Version 10 is already available.

01-13-2016 17:56:40.182    CIAgent    2768 (0xad0)    CIAgentJob({ID}): Nothing to be downloaded. 01-13-2016 17:56:40.182    CIAgent    2316 (0x90c)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=PersistingCIModels) 

01-13-2016 17:56:40.213    CIAgent    2316 (0x90c)    CIAgentJob({ID}):  CI ScopeId_GUID/DeploymentType_GUID:6 (ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file)) targeted to  (Dependant of policy CI ScopeId_GUID/RequiredApplication_GUID:10) is in scope for evaluation. 01-13-2016 17:56:40.213    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=InvokingSdmMethod) 

01-13-2016 17:56:40.244    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): StartEnactment - CI - ScopeId_GUID/RequiredApplication_GUID 01-13-2016 17:56:40.244    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): StartEnactment - Attempting to invoke Policy Platform Client 01-13-2016 17:56:40.322    CIAgent    2768 (0xad0)    CIAgentJob({ID}): ReportMethodInvocation :: Enactment succeeded 01-13-2016 17:56:40.322    CIAgent    2768 (0xad0)    CIAgentJob({ID}): ReportMethodInvocation :: Obtained lantern reports 

01-13-2016 17:56:40.369    CIAgent    2768 (0xad0)    CIAgentJob({ID}):State - Reporting (scan):: AppModel - ScopeId_GUID/Application_GUID:10 - State = NotInstalled ResolvedState = Available Applicability = Applicable ConfigureState= NotNeeded 01-13-2016 17:56:40.385    CIAgent    2768 (0xad0)    CIAgentJob({ID}):State - Reporting (scan):: Deployment Type - ScopeId_GUID/DeploymentType_GUID:6 - State = NotInstalled ResolvedState = Available Applicability = Applicable ConfigureState= NotNeeded 01-13-2016 17:56:40.463    CIAgent    2728 (0xaa8)    Job({ID}): CI ModelName ScopeId_GUID/Application_GUID version 10 will be INSTALLED. : Task(ScopeId_GUID/RequiredApplication_GUID.10.ContentDownload) 01-13-2016 17:56:40.463    CIAgent    2728 (0xaa8)    Job({ID}): CI ModelName ScopeId_GUID/DeploymentType_GUID version 6 will be INSTALLED. : Task(ScopeId_GUID/Application_GUID.10.ContentDownload) 

01-13-2016 17:56:40.417    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=StateDownloadingContents) 01-13-2016 17:56:40.417    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): DownloadBinaryContents 01-13-2016 17:56:40.417    CIAgent    2728 (0xaa8)    {ID} - Initiating ContentDownload tasks. 01-13-2016 17:56:40.463    CIAgent    2728 (0xaa8)    Job({ID}) : Successfully initialized : Task(ScopeId_GUID/DeploymentType_GUID.6.ContentDownload) 01-13-2016 17:56:40.463    CIAgent    2728 (0xaa8)    Job({ID}) : Successfully initialized : Task(ScopeId_GUID/Application_GUID.10.ContentDownload) 

To download the content for the installation, standard content request processes are used. The components involved on the client side are Location Services, Content Access (CAS), Content Transfer Manager and Data Transfer Manager. On the server side, the components involved include MP_Location and MP_GetDPInfoContent, as well as IIS on the distribution point (DP) where the content will be accessed from.

01-13-2016 17:56:40.572    ContentAccess    2728 (0xaa8)    CContentAccessService::Initialize 01-13-2016 17:56:40.572    ContentAccess    2728 (0xaa8)    CDownloadManager::InitializeFromWmi 01-13-2016 17:56:40.572    ContentAccess    2728 (0xaa8)    ===== CacheManager: Initializing cache state from Wmi. ===== 01-13-2016 17:56:40.588    ContentAccess    2728 (0xaa8)    Loading cache configuration from Wmi. 01-13-2016 17:56:42.166    ContentAccess    2728 (0xaa8)    CacheManager: Getting cached content information for Content_GUID.1. 

01-13-2016 17:56:42.432    ContentTransferManager    2768 (0xad0)    Attempting to create Location Request for PackageID='PackageID' and Version='1' 01-13-2016 17:56:42.448    ContentTransferManager    2768 (0xad0)    Attempting to send Location Request for PackageID='Content_GUID' 01-13-2016 17:56:42.448    ContentTransferManager    2728 (0xaa8)    Created CTM job {ID} for user S-1-5-18 01-13-2016 17:56:42.448    ContentTransferManager    2768 (0xad0)    ContentLocationRequest : <ContentLocationRequest SchemaVersion="1.00" ExcludeFileList=""><Package ID="UID:Content_GUID" Version="1"/><AssignedSite SiteCode="MEH"/><ClientLocationInfo LocationType="SMSUpdate" DistributeOnDemand="0" UseAzure="0" AllowWUMU="0" UseProtected="0" AllowCaching="0" BranchDPFlags="0" UseInternetDP="0" AllowHTTP="1" AllowSMB="0" AllowMulticast="0"><ADSite Name="Default-First-Site-Name"/><Forest Name="contoto.lab"/><Domain Name="contoto.lab"/><IPAddresses><IPAddress SubnetAddress="10.10.25.128" Address="10.10.25.130"/><IPAddress SubnetAddress="10.10.25.128" Address="10.10.25.166"/></IPAddresses></ClientLocationInfo></ContentLocationRequest> 01-13-2016 17:56:42.463    ContentTransferManager    2768 (0xad0)    Created and Sent Location Request '{ID}' for package Content_GUID 01-13-2016 17:56:42.463    ContentTransferManager    2768 (0xad0)    CTM job {ID} entered phase CCM_DOWNLOADSTATUS_DOWNLOADING_DATA 

01-13-2016 17:56:42.516    MP_LocationManager    4044 (0xfcc)    MP_GetContentDPInfoProtected (UID:Content_GUID,1,MEH,<ServerNameList><ServerName>PS1DP.CONTOTO.LAB</ServerName></ServerNameList>,SMSUpdate,00000000,contoto.lab,contoto.lab,<ClientLocationInfo LocationType="SMSUpdate" DistributeOnDemand="0" UseAzure="0" AllowWUMU="0" UseProtected="0" AllowCaching="0" BranchDPFlags="0" UseInternetDP="0" AllowHTTP="1" AllowSMB="0" AllowMulticast="0"><ADSite Name="DEFAULT-FIRST-SITE-NAME"/><Forest Name="contoto.lab"/><Domain Name="contoto.lab"/><IPAddresses><IPAddress SubnetAddress="10.10.25.128" Address="10.10.25.130"/><IPAddress SubnetAddress="10.10.25.128" Address="10.10.25.166"/></IPAddresses></ClientLocationInfo>) 

01-13-2016 17:56:42.523    MP_LocationManager    4044 (0xfcc)    MP LM: Reply message body: <ContentLocationReply SchemaVersion="1.00" ContentFlags="200960" HashAlgorithm="32780" AlgorithmPreference="4" Hash="HashString" ExcludeFileListHash="" RelatedContentID=""><ContentInfo PackageFlags="32"><ContentHashValues><Hash Algorithm="32780" HashString="HashString" HashPreference="4"/></ContentHashValues></ContentInfo><Sites><Site><MPSite SiteCode="MEH" MasterSiteCode="MEH" SiteLocality="LOCAL" IISPreferedPort="80" IISSSLPreferedPort="443"/><LocationRecords><LocationRecord><URL Name="http://PS1DP.contoto.lab/SMS_DP_SMSPKG$/Content_GUID.1" Signature="http://PS1DP.contoto.lab/SMS_DP_SMSSIG$/Content_63fbf078-1815-4e37-9614-b60ce7947805.1.tar"/><ADSite Name="Default-First-Site-Name"/><IPSubnets><IPSubnet Address="10.10.25.128"/><IPSubnet Address=""/></IPSubnets><Metric Value=""/><Version>8239</Version><Capabilities SchemaVersion="1.0"><Property Name="SSLState" Value="0"/></Capabilities><ServerRemoteName>PS1DP.contoto.lab</ServerRemoteName><DPType>SERVER</DPType><Windows Trust="1"/><Locality>LOCAL</Locality></LocationRecord></LocationRecords></Site><Site><MPSite SiteCode="MEH" MasterSiteCode="MEH" SiteLocality="LOCAL"/><LocationRecords/></Site></Sites><RelatedContentIDs/></ContentLocationReply>

01-13-2016 17:56:42.510    LocationServices    2752 (0xac0)    ContentLocationReply : <ContentLocationReply SchemaVersion="1.00" ContentFlags="200960" HashAlgorithm="32780" AlgorithmPreference="4" Hash="6FB054E0532351D888291FF52F74E0085940AEA90EC85A5B999B6CFBE94663FC" ExcludeFileListHash="" RelatedContentID=""><ContentInfo PackageFlags="32"><ContentHashValues><Hash Algorithm="32780" HashString="6FB054E0532351D888291FF52F74E0085940AEA90EC85A5B999B6CFBE94663FC" HashPreference="4"/></ContentHashValues></ContentInfo><Sites><Site><MPSite SiteCode="MEH" MasterSiteCode="MEH" SiteLocality="LOCAL" IISPreferedPort="80" IISSSLPreferedPort="443"/><LocationRecords><LocationRecord><URL Name="http://PS1DP.contoto.lab/SMS_DP_SMSPKG$/Content_63fbf078-1815-4e37-9614-b60ce7947805.1" Signature="http://PS1DP.contoto.lab/SMS_DP_SMSSIG$/Content_63fbf078-1815-4e37-9614-b60ce7947805.1.tar"/><ADSite Name="Default-First-Site-Name"/><IPSubnets><IPSubnet Address="10.10.25.128"/><IPSubnet Address=""/></IPSubnets><Metric Value=""/><Version>8239</Version><Capabilities SchemaVersion="1.0"><Property Name="SSLState" Value="0"/></Capabilities><ServerRemoteName>PS1DP.contoto.lab</ServerRemoteName><DPType>SERVER</DPType><Windows Trust="1"/><Locality>LOCAL</Locality></LocationRecord></LocationRecords></Site><Site><MPSite SiteCode="MEH" MasterSiteCode="MEH" SiteLocality="LOCAL"/><LocationRecords/></Site></Sites><RelatedContentIDs/></ContentLocationReply>

01-13-2016 17:56:42.526    LocationServices    2752 (0xac0)    Distribution Point='http://PS1DP.contoto.lab/SMS_DP_SMSPKG$/Content_GUID.1', Locality='LOCAL', DPType='SERVER', Version='8239', Capabilities='<Capabilities SchemaVersion="1.0"><Property Name="SSLState" Value="0"/></Capabilities>', Signature='http://PS1DP.contoto.lab/SMS_DP_SMSSIG$/Content_GUID.1.tar', ForestTrust='TRUE',

01-13-2016 17:56:42.526    ContentTransferManager    2752 (0xac0)    Persisted locations for CTM job {ID}: (LOCAL) http://PS1DP.contoto.lab/SMS_DP_SMSPKG$/Content_GUID.1

01-13-2016 17:56:42.541    ContentTransferManager    2752 (0xac0)    CTM job {ID} (corresponding DTS job {ID}) started download from 'http://PS1DP.contoto.lab/SMS_DP_SMSPKG$/Content_GUID.1' for full content download. 

01-13-2016 17:56:42.541    DataTransferService    2752 (0xac0)    Sending PROPFIND request using URL http://PS1DP.contoto.lab:80/SMS_DP_SMSPKG$/Content_GUID.1 01-13-2016 17:56:42.557    DataTransferService    2752 (0xac0)    UpdateURLWithTransportSettings(): NEW URL - http://ps1dp.contoto.lab:80/SMS_DP_SMSPKG$/Content_GUID.1/sccm?/ConfigMgrTools.msi 01-13-2016 17:56:42.573    DataTransferService    2752 (0xac0)    Starting BITS download for DTS job '{ID}'. 01-13-2016 17:56:42.573    DataTransferService    2752 (0xac0)    BITSHelper: Full source path to be transferred = http://PS1DP.contoto.lab:80/SMS_DP_SMSPKG$/Content_GUID.1/sccm?/ConfigMgrTools.msi

01-13-2016 17:56:42.666    DataTransferService    2748 (0xabc)    Job: {ID}, Total Files: 1, Transferred Files: 0, Total Bytes: 5664768, Transferred Bytes: 262144 01-13-2016 17:56:42.869    DataTransferService    1568 (0x620)    Job: {ID}, Total Files: 1, Transferred Files: 1, Total Bytes: 5664768, Transferred Bytes: 5664768 01-13-2016 17:56:42.885    DataTransferService    2752 (0xac0)    DTSJob {ID} in state 'NotifiedComplete'. 01-13-2016 17:56:42.885    DataTransferService    2752 (0xac0)    DTS job {ID} has completed: Status : SUCCESS, 

01-13-2016 17:56:42.901    ContentTransferManager    2728 (0xaa8)    CCTMJob::_Cleanup(JobID={ID}) - Cancelling DTS job  with provider <default> 01-13-2016 17:56:42.901    ContentAccess    2348 (0x92c)    Using hash from LS Content Information: HashString 

01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    Computed hash: HashString 01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    Success hash verification with hash algorithm = 32780, preference : 4 

01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    Saved Content ID Mapping Content_GUID.1, C:\WINDOWS\ccmcache\1 01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    CacheManager: ADD new cache entry for id:Content_GUID Version : 1 Size : 5532K RefCount:1 LastRef Minutes : 0 State : ACTIVE PinDuration : 0 Location : C:\WINDOWS\ccmcache\1 01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    Created a New Cache Item at location C:\WINDOWS\ccmcache\1 for 1.Content_GUID Size 5532 KB bytes 01-13-2016 17:56:42.948    ContentAccess    2348 (0x92c)    Download succeeded for download request {GUID} 

01-13-2016 17:56:43.041    CIAgent    2316 (0x90c)    CIAgentJob({ID}): TransitionState(From=StateDownloadingContents, To=StateEnforcingCIs) for Event=Transition 01-13-2016 17:56:43.041    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): EnforceCIs 01-13-2016 17:56:43.041    CIAgent    2728 (0xaa8)    {ID} - Initiating Enforce tasks. 01-13-2016 17:56:43.073    CIAgent    2728 (0xaa8)    Job({ID}) : Performing : Task(ScopeId_GUID/RequiredApplication_GUID.10.Enforce) 01-13-2016 17:56:43.073    CIAgent    2728 (0xaa8)    Job({ID}) : Performing : Task(ScopeId_GUID/Application_GUID.10.Enforce) 01-13-2016 17:56:43.073    CIAgent    2728 (0xaa8)    Job({ID}) : Performing : Task(ScopeId_GUID/DeploymentType_GUID.6.Enforce)

Now comes the work of enforcing the installation of the application which will utilize the standard Application Install components and flow: AppDiscovery and AppEnforce.

ActionType - Install,Max execute time = 120 minutes for AppDT "ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file)" [ScopeId_GUID/DeploymentType_GUID], Revision - 6 

01-13-2016 17:56:43.104    AppEnforce    2216 (0x8a8)    +++ Starting Install enforcement for App DT "ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file)" ApplicationDeliveryType - ScopeId_GUID/DeploymentType_GUID, Revision - 6, ContentPath - C:\WINDOWS\ccmcache\1, Execution Context - Any 01-13-2016 17:56:44.666    AppEnforce    2216 (0x8a8)    +++ Application not discovered. [AppDT Id: ScopeId_GUID/DeploymentType_GUID, Revision: 6] 

01-13-2016 17:56:44.682    AppEnforce    2216 (0x8a8)    App enforcement environment:  Context: Machine   Command line: msiexec /i "ConfigMgrTools.msi" /q /L*V "C:\Windows\CCM\Logs\MSI_install.log"   Allow user interaction: No   UI mode: 0   User token: null Session   Id: 4294967295 Content   path: C:\WINDOWS\ccmcache\1 Working directory: 01-13-2016 17:56:44.682    AppEnforce    2216 (0x8a8)    Prepared working directory: C:\WINDOWS\ccmcache\1 01-13-2016 17:56:44.713    AppEnforce    2216 (0x8a8)    Parsed CmdLine: msiexec /i "ConfigMgrTools.msi" /q /L*V "C:\Windows\CCM\Logs\MSI_install.log" 01-13-2016 17:56:44.713    AppEnforce    2216 (0x8a8)    Found executable file msiexec with complete path C:\WINDOWS\system32\msiexec.exe 01-13-2016 17:56:45.666    AppEnforce    2216 (0x8a8)    Executing Command line: "C:\WINDOWS\system32\msiexec.exe" /i "ConfigMgrTools.msi" /q /L*V "C:\Windows\CCM\Logs\MSI_install.log" /qn with system context 01-13-2016 17:56:44.729    AppEnforce    2216 (0x8a8)    Parsed CmdLine: "C:\WINDOWS\system32\msiexec.exe" /i "ConfigMgrTools.msi" /q /L*V "C:\Windows\CCM\Logs\MSI_install.log" /qn 01-13-2016 17:56:45.666    AppEnforce    2216 (0x8a8)    Executing Command line: "C:\WINDOWS\system32\msiexec.exe" /i "ConfigMgrTools.msi" /q /L*V "C:\Windows\CCM\Logs\MSI_install.log" /qn with system context 

=== Verbose logging started: 1/13/2016  17:56:45  Build type: SHIP UNICODE 5.00.9600.00  Calling process: C:\WINDOWS\system32\msiexec.exe === 

MSI (c) (BC:EC) [17:56:47:604]: MainEngineThread is returning 0 01-13-2016 17:56:47.979    InstallApplication    1384 (0x568)    NotifyProgress received: 1 (Application is installed successfully ) 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Installation job completed with exit code 0x00000000 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Execution status received: 1 (Application is installed successfully ) 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Setting TSEnv variable '_TSAppInstallStatus'='Success' 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Setting TSEnv variable 'SMSTSInstallApplicationJobID__ScopeId_GUID/Application_GUID'='' 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Step 2 out of 2 complete 01-13-2016 17:56:48.010    InstallApplication    1608 (0x648)    Sending success status message 

01-13-2016 17:56:47.620    AppEnforce    2216 (0x8a8)    Looking for exit code 0 in exit codes table... 01-13-2016 17:56:47.620    AppEnforce    2216 (0x8a8)    Found a match in the success exit codes. 01-13-2016 17:56:47.620    AppEnforce    2216 (0x8a8)    Matched exit code 0 to a Success entry in exit codes table. 01-13-2016 17:56:47.620    AppEnforce    2216 (0x8a8)    Performing detection of app deployment type ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file)(ScopeId_GUID/DeploymentType_GUID, revision 6) for system. 01-13-2016 17:56:47.635    AppEnforce    2216 (0x8a8)    +++ Discovered application [AppDT Id: ScopeId_GUID/DeploymentType_GUID, Revision: 6] 01-13-2016 17:56:47.635    AppEnforce    2216 (0x8a8)    ++++++ App enforcement completed (4 seconds) for App DT "ConfigMgr 2012 Toolkit R2 - Windows Installer (*.msi file)" [ScopeId_GUID/DeploymentType_GUID], Revision: 6, User SID: ] ++++++ 

All this time, CI Agent has been checking with CI State Store for the Enforcement State of the CIs. DCM Agent has been doing the same as well, monitoring the progress and logging it to DCMAgent.log. Now that the installation is complete and detection has marked it as installed, CI State Store will detect that the state of an existing CI has changed from Enforcing to EnforcementSuccess.

01-13-2016 17:56:47.667    CIStateStore    2728 (0xaa8)    An existing CI state is changed 01-13-2016 17:56:47.667    CIStateStore    2728 (0xaa8)    [ScopeId_GUID/DeploymentType_GUID:6] CIEnforceState changed: Enforcing --> EnforcementSuccess 01-13-2016 17:56:47.729    CIStateStore    2348 (0x92c)    An existing CI state is changed 01-13-2016 17:56:47.776    CIStateStore    2728 (0xaa8)    [ScopeId_GUID/RequiredApplication_GUID:10] CIEnforceState changed: Enforcing --> EnforcementSuccess 

01-13-2016 17:56:47.823    CIAgent    2348 (0x92c)    JobTaskHelper - Initiating next task if needed 01-13-2016 17:56:47.823    CIAgent    2348 (0x92c)    Job({ID}): Already Completed : Task(ScopeId_GUID/DeploymentType_GUID.6.Enforce) 01-13-2016 17:56:47.823    CIAgent    2348 (0x92c)    Job({ID}): Already Completed : Task(ScopeId_GUID/Application_GUID.10.Enforce) 01-13-2016 17:56:47.823    CIAgent    2348 (0x92c)    Job({ID}): Already Completed : Task(ScopeId_GUID/RequiredApplication_GUID.10.Enforce) 01-13-2016 17:56:47.838    CIAgent    2316 (0x90c)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=StateEnforcementReporting) 

01-13-2016 17:56:47.932    CIStateStore    2316 (0x90c)    [ScopeId_GUID/RequiredApplication_GUID:10] CIState changed: NonCompliant --> Compliant 

01-13-2016 17:56:47.963    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=Completed) 01-13-2016 17:56:47.963    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): CAgentJob::HandleEvent(Event=Transition, CurrentState=Completed) 01-13-2016 17:56:47.963    CIAgent    2728 (0xaa8)    CIAgentJob({ID}): Deleting CIAgent Job 01-13-2016 17:56:47.963    CIAgent    2728 (0xaa8)    Deleted CIAgent job {ID} 

01-13-2016 17:56:47.979    DCMAgent    1384 (0x568)    CAppMgmtSDK::GetEvaluationState ScopeId_GUID/RequiredApplication_GUID.10 = Enforced 01-13-2016 17:56:47.979    DCMAgent    2316 (0x90c)    DCMAgentJob({ID}): CDCMAgentJob::HandleEvent(Event=NotifyProgress, CurrentState=Success) 01-13-2016 17:56:47.979    InstallApplication    1608 (0x648)    Received job completion notification from DCM Agent 01-13-2016 17:56:47.995    DCMAgent    2348 (0x92c)    CDCMAgentJobMgr::DeleteJob - Request to delete DCM Agent job {ID} 

01-13-2016 17:56:48.073    TSManager    2176 (0x880)    Process completed with exit code 0 01-13-2016 17:56:48.073    TSManager    2176 (0x880)    Successfully completed the action (Install Application) with the exit win32 code 0 

There are three likely points of failure when executing an Install Application task. Each is listed below with links to troubleshooting steps for each.

Task Sequence Manager

01-13-2016 17:32:54.579    MP_GetPolicy_ISAPI    12688 (0x3190)    MP GP: Query String Before Decode: MEH20009-MEH0000A-6F6BCC28.15_00 01-13-2016 17:32:54.579    MP_GetPolicy_ISAPI    12688 (0x3190)    MP GP: ID : MEH20009-MEH0000A-6F6BCC28 01-13-2016 17:32:54.579    MP_GetPolicy_ISAPI    12688 (0x3190)    MP GP: Initializing request from client GUID:ClientGUID. 

exec MP_GetPolicyBodyAfterAuthorization  

Task Sequence variables

The results of the policy body request are returned to the machine and saved in the task sequence environment (TSEnv.dat). The policy body for the task sequence and all its dependent polices are stored here using variables. Task Sequence Manager will log a large portion of what it is reading from the environment.

InstallApplication    296 (0x128)    App install failed. InstallApplication    296 (0x128)    Install application action failed: 'APP NAME HERE'. Error Code 0x80004005 

Examine the following log files to gain clues as to where this process is failing:

• CIDownloader.log
• DCMAgent.log
• CIStore.log
• CIStateStore.log
• DataTransferService.log

At this point in the task sequence we have requested and downloaded content several times. This was accomplished using the standard content request/response procedures that are used in standard software/application installs outside of a task sequence. Because the task sequence has already used these procedures successfully there is a low probability of them failing during this task. However, should problems arise with content location requests or access, examine the following log files to gain clues as to where the process is failing:

• CIAgent.log
  
• CAS.log
• ContentTransferManager.log
• DataTransferService.log
• LocationServices.log
• MP_Location.log
  

• The application must be a deployment type of Windows Installer or Script installer. Note that Windows app package (.appx file) deployment types are not supported.
  
• It must run under the local system account and not the user account.
  
• It must not interact with the desktop. The program must run silently or in an unattended mode.
  
• It must not initiate a restart on its own. The application must request a restart by using the standard restart code (a 3010 exit code). This ensures that the task sequence step will handle the restart correctly. If the application does return a 3010 exit code, the underlying task sequence engine performs the restart. After the restart the task sequence automatically continues.