Troubleshoot Detection Logic Issue for Updates Created by System Center Update Publisher 2011


<update> Add the link to CSILD description: http://msdn.microsoft.com/en-us/library/windows/desktop/bb762494(v=vs.85).aspx

System Center Update Publisher 2011 provider customers the ability to create customized updates which can be deployed with System Center Configuration Manager: http://www.microsoft.com/download/en/details.aspx?displaylang=en&id=11940.

Some IT admins who use System Center Update Publisher 2011 to create customized updates may face this issue: they create an update and deploy it to SCCM client. However, the update doesn’t show as installable on SCCM clients as expected. This blog provides you the guidance on how to trouble shoot this kind of detection logic issue with verbose enabled WindowsUpdate.log.

Don’t have enough knowledge on SCUP? Check for http://blogs.technet.com/b/jasonlewis/archive/tags/scup/ for a series screencasts for System Center Update Publisher 2011.

Below are the steps to enable WindowsUpdate.log verbose logging and investigate detection logic by reading the log:

  1. Setup a simple SCCM Site + Client environment for SCUP testing.
  2. On the client, let’s enable WUA verbose logging with the traceon.reg:
  3. Create the update in SCUP and deploy to client via SCCM. Record the Update ID from SCUP UI
  4. On client run command net stop wuauserv, delete c:\windows\WindowsUpdate.log and run net start wuauserv to start WUA service.
  5. Then trigger a scan on the client. When scan finished, open WindowsUpdate.log and search for the Update GUID.

Note: After enable verbose log, WindowsUpdate.log will be very large. So make sure you don’t have a lot of updates in the WSUS server you scan against and delete the WindowsUpdate.log every time you start another test.

traceon.reg:

Windows Registry Editor Version 5.00

[HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\WindowsUpdate\Trace]

"Flags"=dword:00000016

"LogFile"="WindowsUpdate.log"

"Level"=dword:00000004

 [HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows\CurrentVersion\WindowsUpdate\Trace\Datastore]

"Flags"=dword:00000016

"Level"=dword:00000003

 

Let’s take the following update for example, it has 5 Installed Rules and 1 Installable Rule. It doesn’t have Prerequisites nor supersede any other updates.

 <smc:SoftwareDistributionPackage SchemaVersion="1.0" xmlns:smc="http://schemas.microsoft.com/sms/2005/04/CorporatePublishing/SystemsManagementCatalog.xsd">
......

      <sdp:IsInstalled>
        <lar:Or xmlns:lar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/LogicalApplicabilityRules.xsd">
          <bar:FileExistsPrependRegSz Path="advert.exe" Value="Path" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" RegType32="true" Size="1048" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
          <bar:FileExistsPrependRegSz Path="advert.exe" Value="Path" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" RegType32="true" Created="2010-10-29T05:19:29" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
          <bar:FileExistsPrependRegSz Path="advert.exe" Value="Path" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" RegType32="true" Modified="2010-10-29T05:19:49" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
          <bar:FileExistsPrependRegSz Path="advert.exe" Value="Path" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" RegType32="true" Language="9" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
          <bar:FileExistsPrependRegSz Path="advert.exe" Value="Path" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" Version="5.2.0.0" Created="2010-10-29T05:20:05" Modified="2010-10-29T05:20:05" Size="1024" Language="9" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
        </lar:Or>
      </sdp:IsInstalled>
      <sdp:IsInstallable>
        <bar:FileExistsPrependRegSz Path="advert.exe" Value="SystemRoot" Key="HKEY_LOCAL_MACHINE" Subkey="SOFTWARE\Microsoft\Windows NT\CurrentVersion" RegType32="true" Version="2.1.1389.0" xmlns:bar="http://schemas.microsoft.com/wsus/2005/04/CorporatePublishing/BaseApplicabilityRules.xsd" />
      </sdp:IsInstallable>
......

</smc:SoftwareDistributionPackage>

After scan finishes, search the update ID in WindowsUpdate.log, and you will find the following lines in the log

2011-10-26          12:10:53:804       948        b28         Agent    Update {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1 will be explicitly evaluated

……

2011-10-26          12:10:53:820       948        b28         Agent    Evaluated Superseded rule, updateId = {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, result = False

2011-10-26          12:10:53:820       948        b28         Perf,      UpdateRule(Superseded), time, 0, {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, handler, none, result = False

2011-10-26          12:10:53:820       948        b28         EEHndlr                Operator Detected: Size=1662,NumRules=5,Operator=2,Weight=5

……

2011-10-26          12:10:53:820       948        b28         EEHndlr                Expression ID is 9

2011-10-26          12:10:53:820       948        b28         EEHndlr                Total number of attributes is 6

2011-10-26          12:10:53:820       948        b28         EEHndlr                Number of variable Length attributes is 3

2011-10-26          12:10:53:820       948        b28         EEHndlr                The full path of the filename is

2011-10-26          12:10:53:820       948        b28         EEHndlr                  EE: FileExistsPrependRegSz evaluated to False, return hr=0

2011-10-26          12:10:53:820       948        b28         EEHndlr                Evaluation of Expression 9 returned hr=0

……

2011-10-26          12:10:53:820       948        b28         EEHndlr                Removing child tree for index 4

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler::Release:refcount is 1

2011-10-26          12:10:53:820       948        b28         EEHndlr                Final Result of the rule evaluation is False

2011-10-26          12:10:53:820       948        b28         Agent    Evaluated Installed rule, updateId = {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, result = False

2011-10-26          12:10:53:820       948        b28         Perf,      UpdateRule(Installed), time, 1, {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, handler, base, result = False

2011-10-26          12:10:53:820       948        b28         EEHndlr                Expression Element detected: Size=318, handlerID=1, weight=1

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler QI: ISusExprEvaluate3

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler::AddRef: refcount is 2

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler::AddRef: refcount is 3

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler::Release: refcount is 2

2011-10-26          12:10:53:820       948        b28         EEHndlr                Expression ID is 9

2011-10-26          12:10:53:820       948        b28         EEHndlr                Total number of attributes is 6

2011-10-26          12:10:53:820       948        b28         EEHndlr                Number of variable Length attributes is 3

2011-10-26          12:10:53:820       948        b28         EEHndlr                The full path of the filename is C:\windows\advert.exe

2011-10-26          12:10:53:820       948        b28         EEHndlr                  EE: FileExistsPrependRegSz evaluated to False, return hr=0

2011-10-26          12:10:53:820       948        b28         EEHndlr                Evaluation of Expression 9 returned hr=0

2011-10-26          12:10:53:820       948        b28         EEHndlr                Expression ID is 9

2011-10-26          12:10:53:820       948        b28         EEHndlr                Total number of attributes is 6

2011-10-26          12:10:53:820       948        b28         EEHndlr                Number of variable Length attributes is 3

2011-10-26          12:10:53:820       948        b28         EEHndlr                Expression Element: Result of Evaluation is False

2011-10-26          12:10:53:820       948        b28         EEHndlr                CSubExpressionHandler::Release:refcount is 1

2011-10-26          12:10:53:820       948        b28         EEHndlr                Final Result of the rule evaluation is False

2011-10-26          12:10:53:820       948        b28         Agent    Evaluated Installable rule, updateId = {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, result = False

2011-10-26          12:10:53:820       948        b28         Perf,      UpdateRule(Installable), time, 0, {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, handler, base, result = False

……

2011-10-26          12:10:53:820       948        b28         Perf,      UpdateRule(IsPresent), time, 1, {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, handler, none, result, 0

2011-10-26          12:10:53:820       948        b28         Agent    Final detection state for update 31 (updateId = {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1) is "NotApplicable"

2011-10-26          12:10:53:820       948        b28         Perf,      DetectForUpdate, time, 0, {68D98E61-C2FF-4638-B0BE-883FC81B4885}.1, handler, base, result, "NotApplicable"

It first evaluated the Superseded rule, since no update supersede this one, so the result is false.

Then it evaluated the Installed rule. It has 5 Installed rules total and the result is false.

Then it evaluated the Installable rule. The result is false too.

So the final result is “NotApplicable”.

The expected result would be:

Installed?

Installable?

Final Result

False

False

NotApplicable

False

True

Applicable (or Required)

True

False/True

Installed

 

We recommend the update author do unit testing for all customized updates in test environment before they deploy them in real world. For each update, before install the update, do the above investigation and make sure the Final Result is Applicable. After install, do the above investigation again and make sure the Final Result is Installed.

Comments (1)
  1. Lawrence Garvin says:

    This would be an even better article if it had a realistic set of rules to demonstrate the behavior of the WUAgent.

    1. Package is Applicable/Required only if advert.exe is v2.1.1389.0

    2. Package is Installed IF….

    – advert.exe has a file size of 1048 bytes

    OR

    – advert.exe has a creation date of 10/29/2010 @5:19:29

    OR

    -advert.exe has a modification date of 10/29/2010 @5:19:49

    OR

    – advert.exe has a LanguageID='9'

    OR

    – advert.exe is v5.2.0.0 AND has a creation date of 10/29/2010 @5:20:05 AND a modification date of 10/29/2010 @5:20:05 AND a file size of 1024 bytes AND a LanugageID='9'.

Comments are closed.

Skip to main content