Problem Description:
Policy tracing is primarily used when debugging access to web sites. When something is allowed and it should be denied, or vice-versa, using the policy trace feature is the best way to diagnose the issue.
Resolution:
Enabling a policy trace
-
- Open the “Configuration” tab, expand “Policy” radio button
- Launch the visual policy manager (VPM)
- Click the “Web access layer (trace)” tab on the VPM
- Right-Click the source of an existing rule and click on ‘Set’
- You can use an IP address or an Active Directory user or group
- For IP address chose – ‘New’, ‘Client IP Address/Subnet’
- Enter the IP address of the workstation you are going to test from, and as subnet, enter 255.255.255.255 since we only want that specific host.
- Verify the ‘Action’ column shows as “None”
- Right click the ‘None’ in the “Track” column and click ‘Set’, ‘New’, ‘Trace…’
- Or you may edit the current tracking object with the following syntax “Policy Trace Name”
- Choose ‘Verbose tracking’, enable ‘Trace file’ and enter a file name
- You should now have a layer with a single rule
- The source should be the IP address of the workstation, and the track object should be the object just created.
- Install the policy
- Reproduce the issue
- After you are finished obtaining the policy trace file – Disable or delete the web access layer just created. It’s best to disable it for now in case another test needs to be done.
Analyzing the policy trace
To open the debug file generated by the policy trace, go to https://:8082/policy
You should see policy trace filenames in there. The file name will depend on the name of the object you created. Click on the file to display it. The default extension is html but the content of the file is plain text. A typical policy trace will look like the one found below. The numbers in red are explained in more details after the trace output below..
start transaction ------------------- (1) CPL Evaluation Trace: transaction ID=659540 (2) miss : time.utc=1800..2000 miss : category=(Alcohol, Auctions, Gambling) DENY (3) MATCH: ALLOW (4) connection: service.name=HTTP client.address=10.1.1.10 proxy.port=8080 (5) time: 2009-06-15 16:38:02 UTC GET http://www.google.com/ (6) Referer: http://www.google.com/ User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9.0.11) Firefox/3.0.11 (7) user: unauthenticated (8) url.category: Search Engines/Portals@Blue Coat (9) DSCP client outbound: 65 DSCP server outbound: 65 stop transaction -------------------- (1)
- (1) Start/Stop markers
Those markers show the top and bottom of every transaction. A transaction is a web transaction. A ‘Get’ request for example. Accessing one web site will generate many transactions since every object (html code, java, images, banners, everything has it’s own transaction). - (2) Layer markers
and are the most popular layer types. A layer marker means that a new layer was evaluated. When a transaction is evaluated against the policy every layer is part of that evaluation (unless it has a layer guard). Rules are evaluated from the top down, and once a rule is a match, the proxy jumps to the next layer. If you have a layer with 30 rules for example but only the first 10 were evaluated, it’s because the 10th rule was a match and the proxy didn’t look at the rest of that layer. - (3) Rule evaluated with a “miss”
In the above example, this rule doesn’t have a source condition, has 3 categories set as destination and ‘Deny’ configured as the action. The policy debug shows “miss” for this rule which means that this transaction did not match the condition. In this case here, google.com did not match the BCWF categories “Alcohol”, “Auctions” or “Gambling” - (4) Rule evaluated with a “MATCH”
This rule was a match so an action was taken by the proxy. In this example, there are no conditions, it’s simply a rule with an “Allow” action so everything would match that rule. Not that this is the last rule evaluated so that means the proxy reached the end of the active policy. - (5) Connection information
This line shows connection details specific to that transaction. We know that the service was HTTP, that the source IP was 10.1.1.10 and that the port used to connect to the proxy was 8080 - (6) The actual request
For our example above, we can see that it was a “get” request made to www.google.com. Most common types of requests are “get”, when the browser fetches an object, and “post”, when information is sent from the browser back to the server (form information and file uploads for example).- http:// Regular web connection
- ssl:// Intercepted SSL connection
- tcp:// Tunneled connection
- (7) The user agent
This line is important when debugging a problem with a web site. We can see that it was Firefox 3.0.11 that made this request, which means it’s the browser itself. Some user-agents out there will make a request directly. Winamp, Microsoft Outlook and iTunes are examples of user-agents that go directly to the internet. Those user-agent don’t support everything that a browser does so they sometimes cause problems, especially with authentication. Usually, the result of that is the user getting prompted to enter credentials. We have seen occurrences of iTunes going into a loop of authentication when the proxy was setup in a transparent way and authentication was configured to use cookie surrogates. The iTunes user-agent would not save the cookie and make the request over and over again, and the proxy would. - (8) Authentication status
If a username was bound to a connection, it would show up here as domain\username. In the example above, the connection was unauthenticated - (9) Category
url.category shows he matching category (or categories) bound to the URL accessed. If you see “unlicensed/unavailable”, it means that the license for the content filtering database has expired.- NOTE: Remember to turn off policy tracing after debugging is complete. Policy tracing (specially enabling tracing for all policy evaluation) will generate lots of logs so it should be turned off when not in use.