ConfigMgr 2012 Log: OfflineServicingMgr.log

I like browsing through log files, especially new log files I haven’t seen before.  They’re treasure troves of information that everyday users of the ConfigMgr GUI should discover and get acquainted with.  With ConfigMgr 2012 we have an influx of new information relating to the new activities we can perform.

Below we have a cycle of events from the OfflineServicingMgr.log, which gives us an insight as to what happens when we perform Image Servicing using the ConfigMgr 2012 console.  The Image Servicing feature lows us to more easily apply Software Updates to our captured reference image without having to resort to command line tools or third party utilities.

If you have a nervous disposition to log files, look away now…

OfflineServicingMgr.log

23/03/2012 09:56:16 SMS_EXECUTIVE started SMS_OFFLINE_SERVICING_MANAGER as thread ID 5832 (0x16C8).
23/03/2012 09:56:16 Checking if there are schedule(s) which need to be run at this time.
23/03/2012 09:56:16 Schedule with ID 16777217 (Schedule Name = ) is marked for RunNow by the administrator
23/03/2012 09:56:16 The Schedule with ID 16777217 will be run now. It's run time is at Fri Mar 23 09:56:16 2012 GMT Standard Time
23/03/2012 09:56:16 Schedule with ID 16777217 () is active
23/03/2012 09:56:16 Schedule processing thread started. ThreadID = 0xD08 (3336) 23/03/2012 09:56:16 1 Schedule(s) are marked for RunNow by the administrator
23/03/2012 09:56:16 1 Schedule(s) are scheduled to be run at this time 23/03/2012 09:56:16 Processing started for Schedule with ID 16777217 (Schedule Name = )
23/03/2012 09:56:16 STATMSG: ID=7900 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 09:56:16.443 2012 ISTR0="16777217" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 09:56:16 Initialization of schedule processing succeeded
23/03/2012 09:56:16 There is an image associated with this schedule.
23/03/2012 09:56:16 Total number of individual updates to be installed is 5.
23/03/2012 09:56:16 STATMSG: ID=7903 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 09:56:16.567 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 09:56:16 Copy image MS10000A (size 0 MB):'
23/03/2012 09:56:16 copying file '\\server\sources\Operating System Images\win7entsp1x64_v1.wim' to 'F:\ConfigMgr_OfflineImageServicing\MS10000A\win7entsp1x64_v1.wim' ...
23/03/2012 09:57:32 Copying(25% complete)...
23/03/2012 09:58:40 Copying(50% complete)...
23/03/2012 09:59:50 Copying(75% complete)...
23/03/2012 10:00:59 Copying(100% complete)...
23/03/2012 10:01:00 STATMSG: ID=7905 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:01:00.042 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:01:00 [Schedule ID 16777217] Started processing image package with ID MS10000A
23/03/2012 10:01:00 STATMSG: ID=7906 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:01:00.043 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:01:00 Image package file with ID MS10000A contains 1 image(s)
23/03/2012 10:01:00 Processing image at index 1 23/03/2012 10:01:00 Mounting image at index 1. Image file='F:\ConfigMgr_OfflineImageServicing\MS10000A\win7entsp1x64_v1.wim', MountDirectory='F:\ConfigMgr_OfflineImageServicing\MS10000A\ImageMountDir', ImageFileType='WIM', Mode='ReadWrite'
23/03/2012 10:01:36 Image OS information : MajorVersionMS = 6, MinorVersionMS = 1, MajorVersionLS = 7601, MinorVersionLS = 17651
23/03/2012 10:01:36 Checking if update (1 of 5) with ID 16781310 needs to be applied on the image. 1 content binarie(s) are associated with the update.
23/03/2012 10:01:46 Applicability State = APPLICABLE, Update Binary = \\server\sources\Software Updates\Windows 7 Updates\d27e6166-5484-4174-ad94-b5bd0405d3d9\windows6.1-kb2645640-x64.cab.
23/03/2012 10:01:46 Applying update with ID 16781310 on image at index 1.
23/03/2012 10:01:53 STATMSG: ID=7908 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:01:53.163 2012 ISTR0="16781310" ISTR1="MS10000A" ISTR2="1" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:01:53 This update binary was succesfully updated on the mounted image. 
23/03/2012 10:01:53 Checking if update (2 of 5) with ID 16781400 needs to be applied on the image. 1 content binarie(s) are associated with the update.
23/03/2012 10:02:00 Applicability State = APPLICABLE, Update Binary = \\server\sources\Software Updates\Windows 7 Updates\cc887950-d1b5-45a8-aa5d-0bd593defcf6\windows6.1-kb2621440-x64.cab.
23/03/2012 10:02:00 Applying update with ID 16781400 on image at index 1.
23/03/2012 10:02:09 STATMSG: ID=7908 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:02:09.661 2012 ISTR0="16781400" ISTR1="MS10000A" ISTR2="1" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:02:09 This update binary was succesfully updated on the mounted image.
23/03/2012 10:02:09 Checking if update (3 of 5) with ID 16781406 needs to be applied on the image. 1 content binarie(s) are associated with the update.
23/03/2012 10:02:18 Applicability State = APPLICABLE, Update Binary = \\server\sources\Software Updates\Windows 7 Updates\be82d4ec-e2aa-4e31-b0cb-60a71c41a60f\windows6.1-kb2641653-x64.cab.
23/03/2012 10:02:18 Applying update with ID 16781406 on image at index 1.
23/03/2012 10:02:29 STATMSG: ID=7908 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:02:29.005 2012 ISTR0="16781406" ISTR1="MS10000A" ISTR2="1" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:02:29 This update binary was succesfully updated on the mounted image.
23/03/2012 10:02:29 Checking if update (4 of 5) with ID 16781420 needs to be applied on the image. 1 content binarie(s) are associated with the update.
23/03/2012 10:02:39 Applicability State = APPLICABLE, Update Binary = \\server\sources\Software Updates\Windows 7 Updates\9d33f980-59ec-4bee-b83e-6e78c4e21fce\windows6.1-kb2665364-x64.cab.
23/03/2012 10:02:39 Applying update with ID 16781420 on image at index 1.
23/03/2012 10:02:51 STATMSG: ID=7908 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:02:51.428 2012 ISTR0="16781420" ISTR1="MS10000A" ISTR2="1" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:02:51 This update binary was succesfully updated on the mounted image.
23/03/2012 10:02:51 Checking if update (5 of 5) with ID 16781430 needs to be applied on the image. 1 content binarie(s) are associated with the update.
23/03/2012 10:03:02 Applicability State = APPLICABLE, Update Binary = \\server\sources\Software Updates\Windows 7 Updates\5b8222b9-80e8-465f-a827-ef18dcda0a7d\windows6.1-kb2667402-x64.cab.
23/03/2012 10:03:02 Applying update with ID 16781430 on image at index 1.
23/03/2012 10:03:16 STATMSG: ID=7908 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:03:16.952 2012 ISTR0="16781430" ISTR1="MS10000A" ISTR2="1" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:03:16 This update binary was succesfully updated on the mounted image.
23/03/2012 10:03:16 Total number of updates that are succesfully applied on the mounted image is 5
23/03/2012 10:03:16 UnMounting Image (Commit Changes = 1) ...
23/03/2012 10:04:28 STATMSG: ID=7907 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:04:28.799 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:04:28 Completed processing image package MS10000A. Status = Success
23/03/2012 10:04:28 STATMSG: ID=7904 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:04:28.815 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:04:28 Create backup copy for image MS10000A 23/03/2012 10:04:28 copying image file '\\server\sources\Operating System Images\win7entsp1x64_v1.wim' to '\\server\sources\Operating System Images\win7entsp1x64_v1.wim.bak' ...
23/03/2012 10:04:28 Copy image MS10000A (size 0 MB):' 23/03/2012 10:04:28 copying file 'F:\ConfigMgr_OfflineImageServicing\MS10000A\win7entsp1x64_v1.wim' to '\\server\sources\Operating System Images\win7entsp1x64_v1.wim' ...
23/03/2012 10:05:46 Copying(25% complete)...
23/03/2012 10:07:00 Copying(50% complete)...
23/03/2012 10:08:06 Copying(75% complete)...
23/03/2012 10:09:19 Copying(100% complete)...
23/03/2012 10:09:19 A backup copy of the original image is created:
23/03/2012 10:09:19 original file '\\server\sources\Operating System Images\win7entsp1x64_v1.wim' is backed up at '\\server\sources\Operating System Images\win7entsp1x64_v1.wim.bak'
23/03/2012 10:09:19 STATMSG: ID=7905 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:09:19.467 2012 ISTR0="MS10000A" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:09:19 Updated history for image package MS10000A in the database
23/03/2012 10:09:19 Schedule processing succeeded
23/03/2012 10:09:19 Processing completed for Schedule with ID 16777217 (Schedule Name = )
23/03/2012 10:09:19 STATMSG: ID=7901 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_OFFLINE_SERVICING_MANAGER" SYS=server.contoso.local SITE=MS1 PID=2148 TID=3336 GMTDATE=Fri Mar 23 10:09:19.496 2012 ISTR0="16777217" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0
23/03/2012 10:09:19 Schedule processing thread stopped 23/03/2012 10:09:19 Checking if there are schedule(s) which need to be run at this time.
23/03/2012 10:09:19 This Schedule with ID 16777217 does not have a next run time
23/03/2012 10:09:19 No more schedules are found to be run at this time or in the future. Will sleep till a new schedule is created.
23/03/2012 10:09:19 No schedule exists which needs to be run anytime in future.
23/03/2012 10:09:19 Offline Servicing Manager thread is exiting.

From what I can see from this log, ConfigMgr makes a copy of our original .wim file into a “ConfigMgr_OfflineImageServicing” folder and mounts this copied image.  It then determines applicability of the Software Updates we have asked it to apply to the image and applies them as required.  After applying the Software Updates, the changes are committed back to the copied .wim file.  It is a little unclear here, but it looks like our original .wim filename is renamed with a .bak extension and the newly serviced .wim file is then copied over to the original source location.

We should note that disk space requirements can get pretty heavy for this process to complete – you should probably budget on having disk freespace that is at least quadruple the size of your reference image available in order for this process to complete.

What I don’t seem to see once this process has completed is any activity from the Distribution Manager log (distmgr.log,)  When we examine the properties of the Operating System Image from within the ConfigMgr console after this process has completed I find that the Image properties have not been automatically reloaded and the OS Image source version hasn’t been updated.  Now, this may just be because at the time I hadn’t actually assigned any distribution points to the image, however if this is not the case then the servicing utility is only doing half a job for us.

Ideally, given that we can schedule image servicing to happen out of hours, we should also at least be given the option to have the image changes distributed throughout the infrastructure so that deployments the next day would use the updated image.  As it stands, it seems we have to manually reload the image properties and then update our distribution points.

Andy

ConfigMgr 101: Compressing Content for Distribution

Here’s a good tip I found, from somewhere.  When you distribute content from your central site, the distribution manager will compress the content and then transmit this to secondary sites, however this isn’t necessary for all types of files.

There exists a registry key “HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\SMS\Compression” and a String Value for “DontCompressExts”.  You might want to consider adding any additional extensions of files to that list which the server should not waste time attempting to compress, such as .wim files.

Little things like this all add up to make a ConfigMgr environment more efficient.

Andy

 

 

Improving Availability of your remote Branch Distribution Points

Whilst I remember, this is a quick post to share a couple of tips which might help you improve the availability of Windows 7 Branch Distribution Points that you may have operating within your ConfigMgr infrastructure.

  • BIOS Power On Timer – If the BIOS supports it, enable the Power On events each working day to power up the system every morning, ready for business.
  • BIOS Power On after AC Loss – Again, if the BIOS supports it, ensure that in the event of a power failure the system will power up again and boot to the OS (not network!)
  • Windows 7 Recovery Options – If Windows 7 is not shut down correctly, it will default to boot into Recovery mode.  To negate this and always attempt to boot into the OS, run the following command line from an Administrative command prompt;
    bcdedit /set {current} bootstatuspolicy ignoreallfailures

This should help to make your Branch Distribution Point systems a little more resilient to everyday life at remote offices.

Andy

Absolute Power Corrupts, Absolutely.

I am proud to announce a new love in my life (‘a’ new love, not ‘the’ love – that would just be mean!) – a Lenovo ThinkPad  W520.  It’s fantastic and I’m going to fall asleep hugging it.

Lenovo ThinkPad W520

I don’t profess to be a hardware geek, but it is equipped with: a 1920×1080 display, NVidia Quadro 2000M Graphics, Intel Core i7 2760QM 8 Core CPU, 16GB RAM, 160GB SSD, 500GB SATA.

ConfigMgr 101: Detecting and Disabling Bitlocker during OSD Task Sequence

There are quite a few blog posts and articles that provide guidance on how to enable Bitlocker during an OSD Task Sequence, however most (if not all) of them omit critical information as to how to correctly handle the detection and disabling of Bitlocker during the REFRESH scenario.  So here goes…

Out of the box, the standard Client Task Sequence MDT Template has a disabled step for ‘Enable Bitlocker’ and as long as you have either manually or scripted the enable and activation of the TPM chip and completed the Active Directory work required this will do the job of encrypting your OS drive.  You probably already got this far, which is no doubt why you are reading this article.

You then arrive at testing your Task Sequence in the REFRESH scenario (initiating the Task Sequence from within the running OS) and find that if Bitlocker is enabled then your standard Task Sequence fails – as it cannot stage the boot image to your OS drive.  You then add the ‘Disable Bitlocker’ task to the Refresh section of your Task Sequence and this works nicely.  However, your Task Sequence will now fail if you attempt to refresh a system that does not have Bitlocker enabled to be disabled – a poor show by the ‘Disable Bitlocker’ step really.  You could enable the ‘Continue on error’ option on this step, however if the step genuinely fails to disable the Bitlocker protectors then it will still proceed to attempt to stage the boot image, which is far from ideal.

The solution then, is that we need ‘something’ to first check to see if Bitlocker is enabled and use this to govern whether the ‘Disable Bitlocker’ step runs.  I used to use a script I found out on the web but I had to amend it a little so that it worked on both x86 and x64 platforms, by using references to SYSNATIVE rather than the hardcoded paths to managebde.exe – as x86 and x64 require the correct version to be ran.  It worked, eventually, after experimenting with the command line and disabling/enabling 64bit redirection – quite exactly what I did I don’t recall.  Many months later, I needed to do the same again for another customer but I wasn’t happy implementing this again – there had to be something better?

Enter – UDI Preflight Checks!  The MDT User Driven Installation (UDI) Client Task Sequence template includes the ‘Disable Bitlocker’ step by default, but on the condition that a the variable ‘OSDBitlockerStatus’ equals ‘Protected’ – so how does it determine this?  The UDI Task Sequence runs a series of pre-flight checks which, amongst other things, checks to see if Bitlocker is enabled.  The Script responsible for this is called ‘OSDBitlockerState.vbs’ and can be found in the ‘<MDT Toolkit Files Package>\Tools\<platform>\preflight’ folder which gets downloaded locally during build as part of the ‘Use Toolkit Package’ step.  You just need to create a step which runs and passes the script the drive letter (ie: ‘C:’) of the partition to be checked and if Bitlocker is enabled on that partition it will set the ‘OSDBitlockerStatus’ variable to ‘Protected’.  I have a step in my Task Sequence before the ‘Disable Bitlocker’ step which runs the following command;

cscript.exe "%TOOLROOT%\preflight\OSDBitlockerState.vbs" C:

The %TOOLROOT% variable resolves to the correct MDT Tools platform folder for the currently running OS – although the script does appear to be the same in both folders.  You would then add a condition to your ‘Disable Bitlocker’ step to check for this condition prior to restarting into Windows PE.

You now have a Standard Client Task Sequence that performs to the same specification as the UDI Task Sequence template with regard to Checking for and Disabling Bitlocker, and we DO like standardisation!

ConfigMgr 2012 RC2: HTTP Error 401 Access Denied to the Application Catalog Website

This is just a short post about an issue I had where the Configuration Manager 2012 Application Catalog website point started to refuse access to the Application Catalog for all users – returning the HTTP Error 401 – Unauthorised.  I simply had to restart the IIS server from the IIS Admin console and things went back to normal.  Something to keep an eye out for!