SC2012 Configuration Manager Log Flow Series 1 – Adding DP

In this series, I will demonstrate some operations on SC 2012 Configuration Manager and show you what log entries you will see during the process. Hope by doing this, you can gain some troubleshoot experience for SC 2012 Configuration Manager.

In this article, we will discuss the flowchart of adding/updating a DP. Assuming the Site Hierarchy is like below:

When Admin create a package on Site CCB and add DPs to this package, the following happens:

1. Distribution Manager on CCB calculates the hash and inserts the package info in DB.

Distmgr.log on CCB

Start adding package CCB00001... SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:01 3696 (0x0E70)

The Package Action is 2, the Update Mask is 0 and UpdateMaskEx is 0. SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:01 3696 (0x0E70)

Taking package snapshot for package CCB00001 from source C:\novascripts SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:01 3696 (0x0E70)

The size of package CCB00001, version 1 is 1 KBytes SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

CreatePackageSignature() called for Package CCB00001 with version 1 with source as '\\?\C:\novascripts'. KeepUnpackedSignature = 1 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

Successfully created RDC signatures for package CCB00001 version 1 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

Creating hash for algorithm 32780 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

Creating hash for algorithm 32780 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

The hash for algorithm 32780 is 500A333B2DDB2A02073F18D363000E368B62BA79310FAD3EAEE93AC6AD1AE3C5 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

The RDC signature hash for algorithm 32780 is 5049BC1C1B759CF1EA22C55468950B8639B033329068D9B9C7599377BA687549 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:02 3696 (0x0E70)

……

Updating package info for package CCB00001 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:03 3696 (0x0E70)

……

Package CCB00001 is new or has changed, replicating to all applicable sites. SMS_DISTRIBUTION_MANAGER 03.05.2012 14:09:03 3696 (0x0E70)

 

2. Distribution Manager on CCB compress the package and send it to other sites (CCA/CC2/CCS)

Distmgr.log on CCB

Needs to send the compressed package for package CCB00001 to site CC2 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Sending a copy of package CCB00001 to site CC2 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

The reporting site of site CC2 is this site. SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Use drive c for storing the compressed package. SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Incremented ref count on file c:\SMSPKG\CCB00001.PCK.1, count = 1 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Setting CMiniJob transfer root to c:\SMSPKG\CCB00001.PCK.1 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Incremented ref count on file c:\SMSPKG\CCB00001.PCK.1, count = 2 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Decremented ref count on file c:\SMSPKG\CCB00001.PCK.1, count = 1 SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

Created minijob to send compressed copy of package CCB00001 to site CC2. Transfer root = c:\SMSPKG\CCB00001.PCK.1. SMS_DISTRIBUTION_MANAGER 03.05.2012 14:10:18 2900 (0x0B54)

 

Schedule.log on CCB:

======== Processing Jobs ======== SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

Updating the in memory job list... SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

0 jobs found in memory, 3 jobs found in job source. SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

<Activating JOB 00000047> [Software Distribution for test1, Package ID = CCB00001] SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Destination site: CC2, Preferred Address: *, Priority: 2 SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Instruction type: MICROSOFT|SMS|MINIJOBINSTRUCTION|PACKAGE SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Creating instruction file: \\CMV47900.CMV47899CHILD.CMV47890DOM.NET\SMS_CCB\inboxes\schedule.box\tosend\00000047.Iph SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Transfer root: c:\SMSPKG\CCB00001.PCK.1 SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Begin to calculate signature on c:\SMSPKG\CCB00001.PCK.1 SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

……

<Updating JOB 00000047> [Software Distribution for test1, Package ID = CCB00001] SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Destination site: CC2, Preferred Address: *, Priority: 2 SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

    Created new send request ID: 2001ZCCB SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

SMS_SCHEDULER 03.05.2012 14:10:28 3720 (0x0E88)

 

Sender.log on CCB:

Found send request. ID: 2001ZCCB, Dest Site: CC2 SMS_LAN_SENDER 03.05.2012 14:10:43 3964 (0x0F7C)

……

Sending Started [c:\SMSPKG\CCB00001.PCK.1] SMS_LAN_SENDER 03.05.2012 14:10:43 1320 (0x0528)

Attempt to write 799 bytes to \\CMV47904.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\2001ZCCB.PCK at position 0 SMS_LAN_SENDER 03.05.2012 14:10:43 1320 (0x0528)

Attempt to create/open the remote file \\CMV47903.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\20020CCB.TMP SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Created/opened the remote file \\CMV47903.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\20020CCB.TMP SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Attempt to create/open the remote file \\CMV47903.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\20020CCB.TMP SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Created/opened the remote file \\CMV47903.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\20020CCB.TMP SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Sending Started [c:\SCCM_7711_Main_\inboxes\schedule.box\tosend\00000048.Iew] SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Attempt to write 1024 bytes to \\CMV47903.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\20020CCB.TMP at position 0 SMS_LAN_SENDER 03.05.2012 14:10:43 4428 (0x114C)

Wrote 799 bytes to \\CMV47904.CMV47902SUB.CMV47899CHILD.CMV47890DOM.net\SMS_SITE\2001ZCCB.PCK at position 0 SMS_LAN_SENDER 03.05.2012 14:10:43 1320 (0x0528)

Sending completed [c:\SMSPKG\CCB00001.PCK.1] SMS_LAN_SENDER 03.05.2012 14:10:43 1320 (0x0528)

Finished sending SWD package CCB00001 version 1 to site CC2 SMS_LAN_SENDER 03.05.2012 14:10:43 1320 (0x0528)

 

3. Distribution manager on CCA/CC2/CCS gets the package information by replication

Distmgr.log on CCA

Start adding package CCB00001... SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:33 PM 4900 (0x1324)

The Package Action is 2, the Update Mask is 0 and UpdateMaskEx is 0. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:33 PM 4900 (0x1324)

Successfully created/updated the package CCB00001 SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:33 PM 4900 (0x1324)

STATMSG: ID=2311 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_DISTRIBUTION_MANAGER" SYS=CMV47893.CMV47892CHILD.CMV47890DOM.net SITE=CCA PID=2248 TID=4900 GMTDATE=Thu May 03 06:10:33.910 2012 ISTR0="CCB00001" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CCB00001" SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:33 PM 4900 (0x1324)

Updating package info for package CCB00001 SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:34 PM 4900 (0x1324)

Created policy provider trigger for ID CCB00001 SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:34 PM 4900 (0x1324)

Package CCB00001 does not have a preferred sender. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:34 PM 4900 (0x1324)

StoredPkgVersion (0) of package CCB00001. StoredPkgVersion in database is 0. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:34 PM 4900 (0x1324)

SourceVersion (1) of package CCB00001. SourceVersion in database is 1. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:10:34 PM 4900 (0x1324)

 

4. Despooler On Site CCA/CC2/CCB get the compressed copy of the package and de-compress it to the content library.

Despool.log:

Received package CCB00001 version 1. Compressed file - c:\SMSPKG\CCB00001.PCK.1 as c:\SCCM_7711_Main_\inboxes\despoolr.box\receive\PKGmcebd.TRY SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Old package storedUNC path is . SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Use drive c for storing the compressed package. SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

No branch cache registry entries found. SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Uncompressing C:\SMSPKG\CCB00001.PCK to C:\SMSPKG\CCB00001.PCK.temp SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Content Library: C:\SCCMContentLib SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Extracting from C:\SMSPKG\CCB00001.PCK.temp SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Extracting package CCB00001 SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Extracting content CCB00001.1 SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Package CCB00001 (version 0) exists in the distribution source, save the newer version (version 1). SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Stored Package CCB00001. Stored Package Version = 1 SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

STATMSG: ID=4400 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_DESPOOLER" SYS=CMV47893.CMV47892CHILD.CMV47890DOM.net SITE=CCA PID=2248 TID=4364 GMTDATE=Thu May 03 06:16:26.734 2012 ISTR0="CCB00001" ISTR1="\\CMV47893.CMV47892CHILD.CMV47890DOM.net\c$\SMSPKG\CCB00001.PCK" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CCB00001" SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

Despooler successfully executed one instruction. SMS_DESPOOLER 5/3/2012 2:16:26 PM 4364 (0x110C)

 

5. Disctribution Manager on CCA creates a package transfer Job (package content and package signature)

Distmgr.log on CCA

Attempting to add or update a package on a distribution point. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:12:34 PM 4604 (0x11FC)

The current user context will be used for connecting to ["Display=\\CMV47895.CMV47892CHILD.CMV47890DOM.net\"]MSWNET:["SMS_SITE=CCA"]\\CMV47895.CMV47892CHILD.CMV47890DOM.net\. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:12:34 PM 1892 (0x0764)

Successfully made a network connection to \\CMV47895.CMV47892CHILD.CMV47890DOM.net\ADMIN$. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:12:34 PM 1892 (0x0764)

……

The contents for the package CCB00001 hasn't arrived from site CCB yet, will retry later. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:12:35 PM 1892 (0x0764)

 

Start updating the package CCB00001... SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:46 PM 1288 (0x0508)

……

Start adding package to server ["Display=\\CMV47895.CMV47892CHILD.CMV47890DOM.net\"]MSWNET:["SMS_SITE=CCA"]\\CMV47895.CMV47892CHILD.CMV47890DOM.net\... SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:46 PM 1288 (0x0508)

……

The current user context will be used for connecting to ["Display=\\CMV47895.CMV47892CHILD.CMV47890DOM.net\"]MSWNET:["SMS_SITE=CCA"]\\CMV47895.CMV47892CHILD.CMV47890DOM.net\. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:46 PM 3276 (0x0CCC)

Successfully made a network connection to \\CMV47895.CMV47892CHILD.CMV47890DOM.net\ADMIN$. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:46 PM 3276 (0x0CCC)

Signature share exists on distribution point path \\CMV47895.CMV47892CHILD.CMV47890DOM.net\SMSSIG$ SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:46 PM 3276 (0x0CCC)

2:16:47 PM 1140 (0x0474)

Share SMSPKGC$ exists on distribution point \\CMV47895.CMV47892CHILD.CMV47890DOM.net\SMSPKGC$ SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:47 PM 3276 (0x0CCC)

……

Created package transefer job to send compressed copy of package CCB00001 to distribution point ["Display=\\CMV47895.CMV47892CHILD.CMV47890DOM.net\"]MSWNET:["SMS_SITE=CCA"]\\CMV47895.CMV47892CHILD.CMV47890DOM.net\. Transfer root = CCB00001.PCK.DLT.0.1. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:47 PM 3276 (0x0CCC)

JobID = J3L7APA3 SMS_DISTRIBUTION_MANAGER 5/3/2012 2:16:47 PM 3276 (0x0CCC)

 

6. Package transfer manager picks up the job request and if the DP address is open at this time, starts copying data to the remote DP systems shared package inbox location.

PkgXferMgr.log on CCA

Activating job J3L7APA3, for package CCB00001 version 1, Distribution point : CMV47895.CMV47892CHILD.CMV47890DOM.net, Priority: 2 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:16:57 PM 4060 (0x0FDC)

    Need to send package file (CCB00001.PCK.DLT.0.1) SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:16:57 PM 4060 (0x0FDC)

Updating job J3L7APA3 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:16:57 PM 4060 (0x0FDC)

    Created new send request ID: 200RVCCA SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:16:57 PM 4060 (0x0FDC)

……

Job count is 2. SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:07 PM 4060 (0x0FDC)

==== Found 2 send requests in outbox c:\SCCM_7711_Main_\inboxes\PkgTransferMgr.box\requests. SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:07 PM 4060 (0x0FDC)

Send Request 200RVCCA~ Job: J3L7APA3 Destination: CMV47895.CMV47892CHILD.CMV47890DOM.net~ State: Pending Status: Action: None~ Total size: 0 k Remaining: 0 k Heartbeat: 23:16~ Start: 12:00 Finish: 12:00 Retry: 23:17~ SWD PkgID: CCB00001 SWD Pkg Version: 1 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:07 PM 4060 (0x0FDC)

Send Request 200RWCCA~ Job: JXLFDPIC Destination: CMV47894.CMV47892CHILD.CMV47890DOM.net~ State: Pending Status: Action: None~ Total size: 0 k Remaining: 0 k Heartbeat: 23:16~ Start: 12:00 Finish: 12:00 Retry: 23:17~ SWD PkgID: CCB00001 SWD Pkg Version: 1 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:07 PM 4060 (0x0FDC)

 

7. Package transfer manager invokes the remote DP WMI provider on remote DP machine to decompress the package and copy it over to the package share location

PkgXferMgr.log on CCA

Created/opened the remote file \\CMV47895.CMV47892CHILD.CMV47890DOM.net\SMS_DP$\CCB00001.1-9DBF6731A3A2BCE5C9470D4810B94387BB647E02707628BC044E569F14C8CE7F SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:13 PM 4552 (0x11C8)

Sending Started [C:\SCCMContentLib\FileLib\9DBF\9DBF6731A3A2BCE5C9470D4810B94387BB647E02707628BC044E569F14C8CE7F] SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:13 PM 4552 (0x11C8)

Attempt to write 1144 bytes to \\CMV47895.CMV47892CHILD.CMV47890DOM.net\SMS_DP$\CCB00001.1-9DBF6731A3A2BCE5C9470D4810B94387BB647E02707628BC044E569F14C8CE7F at position 0 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:13 PM 4552 (0x11C8)

Wrote 1144 bytes to \\CMV47895.CMV47892CHILD.CMV47890DOM.net\SMS_DP$\CCB00001.1-9DBF6731A3A2BCE5C9470D4810B94387BB647E02707628BC044E569F14C8CE7F at position 0 SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:13 PM 4552 (0x11C8)

……

Completed post-actions for remote DP CMV47894.CMV47892CHILD.CMV47890DOM.net SMS_PACKAGE_TRANSFER_MANAGER 5/3/2012 2:17:13 PM 1760 (0x06E0)

 

 Smsdpprov.log on Remote DP (located in SMS_DP$\sms\logs)

[638][Thu 05/03/2012 14:17:12]:Conent 'CCB00001.1' for package 'CCB00001' has been added to content library successfully

 

8. Distribution Manager Process the .STA file for the package and updates the DB accordingly.

Distmgr.log on CCA

Processing incoming file c:\SCCM_7711_Main_\inboxes\distmgr.box\INCOMING\MXITSIA3.STA. SMS_DISTRIBUTION_MANAGER 5/3/2012 2:17:18 PM 1348 (0x0544)

Processing STA for regular DP ["Display=\\CMV47895.CMV47892CHILD.CMV47890DOM.net\"]MSWNET:["SMS_SITE=CCA"]\\CMV47895.CMV47892CHILD.CMV47890DOM.net\ SMS_DISTRIBUTION_MANAGER 5/3/2012 2:17:18 PM 1348 (0x0544)

Processing status update for package CCB00001 SMS_DISTRIBUTION_MANAGER 5/3/2012 2:17:18 PM 1348 (0x0544)

Successfully updated the package server status for

……

 

Summary on related components and their log files:

Distribution Manager – distmgr.log

Scheduler – scheduler.log

Sender – sender.log

Despooler – despool.log

Package Transfer Manager – PkgXferMgr.log

Remote DP WMI Provider - smsdpprovider.log