O R G A N I C / F E R T I L I Z E R: sccm clients fail to apply a policy

Feb 2, 2010

sccm clients fail to apply a policy

background

recently, we replaced one of our existing configmgr primary site servers with new hardware.  by replacing, i mean the hardware was swapped out, and the site was brought back online through the site repair wizard. 

 

the problem

generally this is a seamless process, but for some reason, a pesky policy kept flagging in the policy evaluator log and failed to apply.  this problem manifested itself on every client.

Applying policy {52b16f0c-cdd7-4be6-be64-6bd836c05553}  PolicyAgent_PolicyEvaluator     2/2/2010 11:32:11 AM    2344 (0x0928)
Failed to load policies from XML. Unknown error (Error: 80040217; Source: Unknown) PolicyAgent_PolicyEvaluator 2/2/2010 11:32:11 AM 2344 (0x0928)
Bad policy dumped to C:\WINDOWS\system32\CCM\Temp\badpolicy-SMS_XYZ-{52b16f0c-cdd7-4be6-be64-6bd836c05553}-2.00-{67c84d26-53aa-45da-af5c-aa04fe46303a}.txt PolicyAgent_PolicyEvaluator 2/2/2010 11:32:12 AM 2344 (0x0928)
Already sent a policy rule application failure status message within the last 6 hours, not sending. PolicyAgent_PolicyEvaluator 2/2/2010 11:32:12 AM 2344 (0x0928)
Failed to apply policy rule {67c84d26-53aa-45da-af5c-aa04fe46303a}. PolicyAgent_PolicyEvaluator 2/2/2010 11:32:12 AM 2344 (0x0928)
The policy CCM_Policy_Policy4.PolicyID="{52b16f0c-cdd7-4be6-be64-6bd836c05553}",PolicySource="SMS:XYZ",PolicyVersion="2.00" failed to compile. State has been set to 'Inactive' and policy will be rolled back. PolicyAgent_PolicyEvaluator 2/2/2010 11:32:12 AM 2344 (0x0928)
Failed to update policy CCM_Policy_Policy4.PolicyID="{52b16f0c-cdd7-4be6-be64-6bd836c05553}",PolicySource="SMS:XYZ",PolicyVersion="2.00" PolicyAgent_PolicyEvaluator 2/2/2010 11:32:12 AM 2344 (0x0928)

since we were seeing this problem site-wide, we knew that the problem was most likely on the server itself.  well, that narrows things down from thousands to one.  :)  nice when statistics works in your favor.

 

isolating the policy through logs

most of you configmgr admins will like this since logs are near and dear to our hearts.  so now you know that a policy is failing, but which policy?  well, according to the log snippet above, the policy we should be looking at is this one:

{52b16f0c-cdd7-4be6-be64-6bd836c05553}

okay, you got the guid… now what?  what’s it mean?  what’s it map back to?  each configmgr server has its own set of unique guids whenever the policies are created.  in other words, you can’t search for the guid and expect something on the internet to give you the right thing to fix. that means i just removed 90% of your troubleshooting effort!  ;)

now it’s critically important to find out what this guid is.  it turns out, there are two ways to discover it.  it’s really about preference.  the easiest way, i found, was to search the entire logs directory of the sccm server.  running something like this on the configmgr server would suffice:

find /i "{52b16f0c-cdd7-4be6-be64-6bd836c05553}" <sccm log path>\*.lo*

assuming the problem exists, it should still be there in the log.  here’s what i found in the policypv.log:

CPolicySource::HandleSiteControlPolicy: NetworkAccessAccount
STATMSG: ID=5104 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_POLICY_PROVIDER" SYS=myMachine SITE=XYZ PID=7452 TID=7144 GMTDATE=Thu Jan 28 15:58:57.874 2010 ISTR0="" ISTR1="" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=2 AID0=405 AVAL0="{52b16f0c-cdd7-4be6-be64-6bd836c05553}" AID1=406 AVAL1="{beacb5c4-441f-4afd-8ae0-24708aca3cfe}"

the line in red is the site control policy that it’s looking at.  the line following is a status message for this policy.  you can see in the line following, the guid is in the position AVAL0.  match!  log is my copilot!

 

isolating the policy through the database

if you don’t like that method, you can always query the database directly.  first of all, we’d have to find the right table to query, right?  we could use a method i outlined in a previous blog post to do a wildcard search for what we suspect the table name might be.  so here goes:

select * from sys.tables where name like '%policy%'

success.  when i execute this, i get a list of 16 possible tables.  (luckily, i was informed of the right table – otherwise i’d have been scouring each one of them.  since i’m such a generous guy, flagged it for you.)

CH_PolicyRequestHistory
PeerDPPkgPolicy
PeerDPPolicy
SoftwarePolicy
SettingsPolicy
ResyncPolicy
MeteringPolicy
PolicyAssignment
DepPolicyAssignment
ResPolicyChange
ResPolicyMap
PolicyCollMap
PolicyCollMapFlat
ResPolicyCollMapChg_Notify
ResPolicyCollMap
Policy

alright, now that we know the table, we can execute another query to find out what the policy is -- or we could just eye ball it, but where’s the fun in that?

select policyid, sourcetype from settingspolicy where policyid = '{52b16f0c-cdd7-4be6-be64-6bd836c05553}'

here’s the result:

{52b16f0c-cdd7-4be6-be64-6bd836c05553}    NetworkAccessAccount

i have to say, this really is a situation where cartoons didn’t waste your life away as your mother would have you believe.  g.i. joe had it right: knowing is half the battle.  now we’re armed with knowledge on where the problem is!  obviously, there’s something jacked up with the network access account.

 

the resolution

since we didn’t know exactly what was wrong with it, we cleared the setting and added a new account and password.  once the new policy was sent back down to the client, the client processed it correctly as indicated in the policy evaluator log:

Updating policy CCM_Policy_Policy4.PolicyID="{52b16f0c-cdd7-4be6-be64-6bd836c05553}",PolicySource="SMS:XYZ",PolicyVersion="3.00"    PolicyAgent_PolicyEvaluator    2/2/2010 2:15:43 PM    872 (0x0368)
Applying policy {52b16f0c-cdd7-4be6-be64-6bd836c05553} PolicyAgent_PolicyEvaluator 2/2/2010 2:15:43 PM 872 (0x0368)
Raising event:

instance of CCM_PolicyAgent_PolicyRuleApplied
{
ClientID = "GUID:9BFE78BD-69F3-4E01-8D93-3D1E125C756C";
DateTime = "20100202201544.041000+000";
PolicyID = "{52b16f0c-cdd7-4be6-be64-6bd836c05553}";
PolicyNamespace = "\\\\myMachine\\ROOT\\ccm\\Policy\\Machine\\RequestedConfig";
PolicySource = "SMS:XYZ";
PolicyVersion = "3.00";
ProcessID = 2908;
RuleCondition = "";
RuleID = "{af6688c2-385e-4ce6-b7c5-22e79ae0efa8}";
ThreadID = 872;
};
PolicyAgent_PolicyEvaluator 2/2/2010 2:15:44 PM 872 (0x0368)
Applied policy CCM_Policy_Policy4.PolicyID="{52b16f0c-cdd7-4be6-be64-6bd836c05553}",PolicySource="SMS:XYZ",PolicyVersion="3.00" PolicyAgent_PolicyEvaluator 2/2/2010 2:15:44 PM 872 (0x0368)
Raising event:

instance of CCM_PolicyAgent_PolicyEvaluationComplete
{
ClientID = "GUID:9BFE78BD-69F3-4E01-8D93-3D1E125C756C";
DateTime = "20100202201544.072000+000";
PolicyNamespace = "\\\\myMachine\\ROOT\\ccm\\Policy\\Machine\\RequestedConfig";
PolicyPath = "CCM_Policy_Policy4.PolicyID=\"{52b16f0c-cdd7-4be6-be64-6bd836c05553}\",PolicySource=\"SMS:XYZ\",PolicyVersion=\"3.00\"";
ProcessID = 2908;
ThreadID = 872;
};
PolicyAgent_PolicyEvaluator 2/2/2010 2:15:44 PM 872 (0x0368)
Updating settings in \\myMachine\root\ccm\policy\machine\actualconfig PolicyAgent_PolicyEvaluator 2/2/2010 2:17:44 PM 872 (0x0368)
Raising event:

instance of CCM_PolicyAgent_SettingsEvaluationComplete
{
ClientID = "GUID:9BFE78BD-69F3-4E01-8D93-3D1E125C756C";
DateTime = "20100202201744.838000+000";
PolicyNamespace = "\\\\myMachine\\root\\ccm\\policy\\machine\\actualconfig";
ProcessID = 2908;
ThreadID = 872;
};
PolicyAgent_PolicyEvaluator 2/2/2010 2:17:44 PM 872 (0x0368)

note: we initially tried clearing the value for the network access account.  that didn’t work.  we had to supply a new value.  after that, everything worked great.

thanks for your help, jason.