Sascha Preibisch

Tip of the week: debugging policy

Blog Post created by Sascha Preibisch Employee on Mar 6, 2017

Hi everybody!

I just received a question, the same one that I have received last week. Therefore I thought, I'll start the series "Tip of the week" with little tips and tricks around building policies.

 

Here is the tip: debugging policy

Debugging policies can be difficult. We do have the policy debugger and we do have a debugging policy. Both tools help, but the out-of-the-box debugging policy is not really producing a meaningful output. Therefore, here is how you should use it (well, how I use it, which may also work for you):

 

  1. Place an Audit Messages in policy assertion into your service and configure it to always capture requests and responses
  2. Do a right-click on the service
  3. Select the service properties, then select Enable policy debug tracing
  4. In the appearing dialog Do you want to edit the debug trace policy now? select Yes
  5. In that policy you want to remove the "Audit Messages in Policy" assertion on line 5
  6. Now select the "Add Audit Details" assertion and let's work on that ...

 

That assertion has this content:

TRACE: service.name=${trace.service.name} policy.name=${trace.policy.name} policy.guid=${trace.policy.guid} assertion.number=${trace.assertion.numberstr} assertion.shortname=${trace.assertion.shortname} status=${trace.status}

As you can see it contains strings such as "service.name", ... "policy.guid", ... these strings are used as labels. That is all good but it makes the audit result difficult to read. It also has the "trace.status" at the end although that may be the most important information you want to look at. Here is an example of the output:

 

 

What you are interested in are error codes (trace.status) and policy line numbers (trace.assertion.numberstr). But they are hidden in the loooooong audit message, right at the end.

 

Your new debugging policy

You can turn this message into something very helpful by replacing the content of the audit detail assertion using this message:

TRACE: [${trace.status}][${trace.assertion.numberstr}][${trace.assertion.shortname}][${trace.policy.name}]

I removed all labels and I moved the important content to the front. I have put variables into [...] brackets. The brackets will contain the following information:

  • 1: [...]: '0' if the assertion executed without error, >0 if an error occured. Depending on your policy you may expect assertions to fail, such as comparisons!
  • 2: [...]: the assertion line number. It will tell you exactly which line was executed. If it shows something like [3.45] read it as: line 3 in the service is a fragment (or encapsulated assertion). Within that fragment (or encapsulated assertion) the policy failed on line 45. If the line numbers are not shown for encapsulated assertions open the encapsulated assertion configuration and enable Allow debug tracing into backing policy
  • 3: [...]: the assertion name
  • 4: [...]: the policy name

 

The output looks like this now:

You will now find failing assertions easier by just checking the value of the first bracket. It will show you the line number  in bracket no. 2 which makes it easy to locate the failing location in policy.

 

I hope this helps making policy debugging easier!

Outcomes