Tracing Package Distribution in the Log Files
It is worth noting here that any time a change is made to a package, be it program, Access
Account settings, Distribution Points, a new notification file is generated at the conclusion of
each change. We can see in the SMSDBMON log that there is another record of another
notification file being created…
CTriggerManager::InstanceThread: pipe=776:
0007SMS_CEN0015PKGNOTIFICATION0006INSERT0008CEN0000E
Received notification: Table=PKGNOTIFICATION, Type=INSERT, KeyName=CEN0000E.
Created notification file C:\SMS\inboxes\distmgr.box\CEN0000E.PKN
Tip Disabling threads of SMS is often very useful in troubleshooting. Doing so is
very easy. Simply identify the DLL associated with the particular thread of SMS_Executive and
rename it. After the rename, restart the SMS_Executive.
When Distribution Manager processes the notification file, it will do all of the tasks that have
been queued up for it. The notification file is created by triggers on the PkgNotification table
and is placed in the SMS\Inboxes\Distmgr.box\ folder. Typically, this file is processed so fast
that we cannot see it. We also do not typically see entries in the PkgNotification table. If
necessary, the distribution manager thread may be stopped to capture this information.
Package processing - Distribution within same site
When Distribution manager receives and processes a notification file, you would see logging
similar to the following in the DISTMGR.LOG.
Starting thread for processing replication,thread ID = AC8
Used 0 out of 3 allowed processing threads.
Starting package processing thread,thread ID = E1C
Sleep 3600 seconds...
STATMSG: ID=2300 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:16.472 2004 ISTR0="Lab 1 - Test
package" ISTR1="CEN0000E" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6=""
ISTR7="" ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CEN0000E"
Here, we see Distribution Manager spawned a new thread to start working on the package
we just created and a status message going back to the site server to record what is
happening.
Start adding package CEN0000E...
The Package Action is 2 and the Update Mask is 0.
Starting to hash C:\Lab1 for package CEN0000E
The hash of package CEN0000E is ABF49912E6D64AAB10C218EC9EA9500B
Package CEN0000E uses the source directory directly.
The size of package CEN0000E is 66 Kbytes
Created policy provider trigger for package CEN0000E
Successfully created/updated the package CEN0000E
STATMSG: ID=2311 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:16.881 2004 ISTR0="CEN0000E"
ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7=""
ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CEN0000E"
In this snip, we see Distribution Manager is starting to add the package. We see it hash the
package and report the result of that hash. The next line mentions the package uses the
source directly – this is a result of setting the switch to get package from source directory. If
we had set the flag to use a compressed copy, the log entry here would be different.
Distribution Manager next reports the size of the package and then reports that it
successfully created a policy trigger followed by a success and a status message, again,
indicating progress back to the site server.
Start adding package to server
["Display=\\LCTOPAZMOM\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZMOM\...
Attempting to add or update a package on a distribution point.
STATMSG: ID=2342 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:16.971 2004 ISTR0="Lab 1 - Test
package"
ISTR1="["Display=\\LCTOPAZMOM\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZMOM\"
ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8=""
ISTR9="" NUMATTRS=2 AID0=400 AVAL0="CEN0000E" AID1=404
AVAL1="["Display=\\LCTOPAZMOM\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZMOM\"
Cannot establish connection to
["Display=\\LCTOPAZMOM\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZMOM\
Error occurred.
Performing error cleanup prior to returning.
In this section of log, we see Distribution Manager starting the process of actually adding the
package to the distribution point – but an error occurs.. What happened? Is this error fatal?
The answer is no because Distribution Manager continues, as we see later. The error simply
means that the target folder did not exist on the distribution point – so Distribution Manager
needs to back up and create it. If the folder had already been there and this was an update,
no problem would have been seen. Therefore, Distribution Manager creates the folder.
Start adding package to server
["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\...
Attempting to add or update a package on a distribution point.
STATMSG: ID=2342 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:17.770 2004 ISTR0="Lab 1 - Test
package"
ISTR1="["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\"
ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8=""
ISTR9="" NUMATTRS=2 AID0=400 AVAL0="CEN0000E" AID1=404
AVAL1="["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\"
Here, we begin the process of moving the package to our distribution point. Remember, this
is a local distribution point. For remote distribution points (defined as those belonging to
another site), this process is a bit different – we will see that in a moment.
Tip ANY distribution point owned by a site is considered local to that site – in other
words, we expect full LAN speed connectivity. For this reason, no efforts are taken
to minimize bandwidth usage when copying to local distribution points as opposed
to distribution points in another site.
Established connection to
["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\
The distribution point
["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\ doesn't
point to an existing path.
Used 1 out of 3 allowed processing threads.
Sleep 3600 seconds...
Here, we see that no existing folder is present for the package – so there is nothing to
update – so we have to create a new folder.
The best drive for installing package on the distribution point
["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\ is C:\
Share SMSPKGC$ exists on distribution point
["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\
Attempting to create subdirectory CEN0000E under the export.
The export is accessible.
Successfully created the package directory CEN0000E\ under the export.
Successfully created sub directory CEN0000E off
MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\
Get access to the package directory and the number of free bytes at
that location.
Attempting to make an accessible connection to
MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\, get its NOS
path, and get its number of free bytes.
Established connection to
MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\Getting the NAL
path's NOS equivalent.
The NOS path is \\LCTOPAZCEN\SMSPKGC$\CEN0000E\
Getting the number of free bytes.
The number of free bytes 7045428
Successfully made an accessible connection, got a NOS path, and, if
requested, got the number of free bytes at this location.
Successfully set access security on
MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\ for package
CEN0000E
In this section, we see Distribution Manager evaluating the best drive to use for the package.
In this case, the package share already exists and so we will use it. We create the
subdirectory, evaluate how much free space we have, and set appropriate security. The
security settings applied are those configured in the ‘Access Accounts’ section of the
Administrator console discussed earlier.
Copying C:\Lab1\NOTEPAD.EXE to C:\SMSPKGC$\CEN0000E\NOTEPAD.EXE, OK
Successfully copied package CEN0000E from C:\Lab1\ to
MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\
STATMSG: ID=2329 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:25.822 2004 ISTR0="CEN0000E"
ISTR1="C:\Lab1\"
ISTR2="MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\SMSPKGC$\CEN0000E\"
ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9=""
NUMATTRS=2 AID0=400 AVAL0="CEN0000E" AID1=404
AVAL1="["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\"
STATMSG: ID=2330 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=3612 GMTDATE=Mon Jun 07 23:23:25.912 2004 ISTR0="CEN0000E"
ISTR1="["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\"
ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8=""
ISTR9="" NUMATTRS=2 AID0=400 AVAL0="CEN0000E" AID1=404
AVAL1="["Display=\\LCTOPAZCEN\"]MSWNET:["SMS_SITE=CEN"]\\LCTOPAZCEN\"
Successfully created/updated the package server in the data source
Performing cleanup prior to returning.
Updating package info for package CEN0000E
Created policy provider trigger for package CEN0000E
Here, we simply copy the package out to the distribution point, update the database and
update WMI.
As we can see from the following snip of the PolicyPV.LOG, when the package is updated, we
also update WMI with detected changes. Not all changes will be sufficient to cause a policy
change, in this example an update to software distribution settings caused the changes being
made in the following log snip.
Looking for settings policy and policy assignments that should be
removed...
Did not find any settings policy and policy assignments that should be
removed. Looking for settings policy and policy assignments that
should be created or updated...
STATMSG: ID=5104 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_POLICY_PROVIDER" SYS=LCTOPAZCEN SITE=CEN PID=2704 TID=2328
GMTDATE=Sat Aug 14 02:15:49.347 2004 ISTR0="" ISTR1="" ISTR2=""
ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9=""
NUMATTRS=2 AID0=405 AVAL0="{5654d9e4-d91d-499b-828c-5a2ea59e48db}"
AID1=406 AVAL1="{4e29d7c1-0333-4193-a798-fdf9fc3a4578}"
Did not find any settings policy and policy assignments that should be
created.
Successfully updated 1 settings policy.
Waiting for changes...
Package processing - Distribution between sites
So, what happens if we are actually sending the package to a distribution point connected to
another site? The basics of the log are the same with a few differences. In the following snip,
we have now added a distribution point at site PRI to the package. Here we see that we do
not simply copy the package to the distribution. Instead, we create a compressed copy of the
package – which, for very large packages, may take a fair amount of time. Once the package
is compressed, it goes through normal sender mechanisms to arrive at the target
Distribution Point.
Updating package info for package CEN0000E
Package CEN0000E does not have a preferred sender.
STATMSG: ID=2333 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=1596 GMTDATE=Wed Jun 09 19:52:07.467 2004 ISTR0="CEN0000E"
ISTR1="PRI" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7=""
ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CEN0000E"
Needs to send the compressed package for package CEN0000E to site PRI
There isn't a copy of compressed copy for package CEN0000E, create it.
Use drive C for storing the compressed package.
The size of package CEN0000E is 66 Kbytes
Starting to compress C:\Lab1 to C:\_S Mlnhr.TMP for package CEN0000E
The compressed size of package CEN0000E is 34 Kbytes
STATMSG: ID=2310 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=1596 GMTDATE=Wed Jun 09 19:52:07.787 2004 ISTR0="CEN0000E"
ISTR1="C:\Lab1" ISTR2="\\LCTOPAZCEN\SMS_CPSC$\CEN0000E.PCK" ISTR3=""
ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=1
AID0=400 AVAL0="CEN0000E"
Sending a copy of package CEN0000E to site PRI
Created minijob to send compressed copy of package CEN0000E to site
PRI. Transfer root = \\LCTOPAZCEN\SMS_CPSC$\CEN0000E.PCK.
STATMSG: ID=2335 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=1596 GMTDATE=Wed Jun 09 19:52:08.127 2004 ISTR0="CEN0000E"
ISTR1="PRI" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7=""
ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CEN0000E"The package
and/or program properties for package CEN0000E have not changed, need
to determine which site(s) need updated package info.
A distribution point has been changed at this site, adding site PRI to
the list of sites to which we are sending package CEN0000E.
Parent site of PRI is CEN
Sent package changes to site PRI for package CEN0000E
STATMSG: ID=2339 SEV=I LEV=M SOURCE="SMS Server"
COMP="SMS_DISTRIBUTION_MANAGER" SYS=LCTOPAZCEN SITE=CEN PID=3808
TID=1596 GMTDATE=Wed Jun 09 19:52:08.237 2004 ISTR0="CEN0000E"
ISTR1="PRI" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7=""
ISTR8="" ISTR9="" NUMATTRS=1 AID0=400 AVAL0="CEN0000E"
StoredPkgVersion (1) of package CEN0000E. StoredPkgVersion in database
is 1.
SourceVersion (1) of package CEN0000E. SourceVersion in database is 1.
It should be noted here that we have not yet created any advertisements. All we have done
thus far is create the Package and Program and deliver it to the distribution point. Often,
packages and advertisements are created at the same time. This is fine. Keep in mind,
however, that until the package actually arrives at the distribution point for the target site,
the advertisement will not be available – even if it has already arrived.
