Cisco WAAS Troubleshooting Guide for Release 4.1.3 and Later -- Troubleshooting the HTTP AO
From DocWiki
This article describes how to troubleshoot the HTTP AO.
Contents |
HTTP Accelerator Troubleshooting
The HTTP accelerator optimizes HTTP traffic using the following techniques:
- TCP connection reuse across the WAN. Avoids a connection setup penalty for subsequent connections requested by the same client.
- HTTP metadata caching. Certain HTTP responses are cached, along with their URLs and metadata information, so that the edge WAE can respond locally to subsequent requests for the same URL. (Available only in version 4.2.1 and later.) The three types of cached responses are as follows:
- 301 Permanently-Redirected
- 304 Not-Modified
- 401 Authorization-Required
- HTTP suppress server encoding. Removes the Accept-Encoding header from the HTTP requests, preventing the server from sending compressed data towards the WAN. This allows the WAE to apply its own compression, typically resulting in a better compression ratio. (Available only in version 4.2.1 and later.)
The HTTP metadata caching and suppress server encoding features can be configured separately. The TCP connection reuse feature is always active when the HTTP AO is enabled.
You can verify the general AO configuration and status with the show accelerator and show license commands, as described in the Troubleshooting Application Acceleration article. The Enterprise license is required for HTTP accelerator operation.
Next, verify the status that is specific to the HTTP AO by using the show accelerator http command, as shown in Figure 1. You want to see that the HTTP AO is Enabled, Running, and Registered, and that the connection limit is displayed. If the Config State is Enabled but the Operational State is Shutdown, it indicates a licensing problem. For each of the HTTP features (metadatacache and suppress-server-encoding) the current mode is shown (User/Default) along with the value (Enabled, Disabled or configured value).
- Figure 1. Verifying the HTTP Accelerator Status
Use the show running-config command to verify that the HTTP traffic policy is properly configured and which of the features is enabled. You want to see accelerate http for the Web application action and you want to see appropriate match conditions listed for the HTTP classifier, as follows:
WAE674# sh run | include HTTP
accelerator http suppress-server-encoding enable <----- in 4.2.1 and later
accelerator http metadatacache enable <----- in 4.2.1 and later
classifier HTTP
classifier HTTPS
name Web classifier HTTP action optimize full accelerate http <-------------
name Web classifier HTTPS action optimize DRE no compression none
WAE674# sh run | begin HTTP
...skipping
classifier HTTP
match dst port eq 80
match dst port eq 8080
match dst port eq 8000
match dst port eq 8001
match dst port eq 3128
Use the show statistics accelerator http command to see the following statistics:
- How much time is being saved by the HTTP AO. You can see the overall Time Saved by the entire HTTP AO or the Time Saved by each of the features:
- Time Saved by fast connection reuse
- Time Saved by the three metadata caches
- Number of cache hits/misses for the metadata caches
- Number of times suppress server encoding is applied to HTTP requests
- Number of times DRE hints are provided based on the content of the HTTP headers
- Number of HTTP transactions (request+response) processed
- Number of errors in the HTTP header processing
- Number of cache revalidations
WAE674# sh stat accel http HTTP: Global Statistics ----------------- Time Accelerator was started: Tue Apr 6 06:04:06 2010 Time Statistics were Last Reset/Cleared: Tue Apr 6 06:04:06 2010 Total Handled Connections: 3743984 Total Optimized Connections: 3743984 Total Connections Handed-off with Compression Policies Unchanged: 0 Total Dropped Connections: 0 Current Active Connections: 48 Current Pending Connections: 0 Maximum Active Connections: 176 Total Time Saved (ms): 35584437 <-----Should be incrementing Current Active Connections Free For Fast Connection Use: 2 Total Connections Handed-off: 0 Total Connections Handed-off with Compression Policies Disabled: 0 Total Connections Handed-off to SSL: 0 Total Connection Hand-off Failures: 0 Total Fast Connection Successes: 3617244 <-----Should be incrementing Total Fast Connection Failures: 0 Maximum Fast Connections on a Single Connection: 100 Total CONNECT Requests with Incomplete Message: 0 Percentage of Connection Time Saved: 37 Total Round Trip Time For All Connections (ms): 4922767377 Total Fast Connections Initiated by Peer: 0 Total SYN Timeouts: 0 Total Time for Metadata Cache Miss (ms): 2 <-----Output from here is in 4.2.1 and later only RTT saved by Redirect Metadata Cache (ms): 5988 <-----Should be incrementing RTT saved by Authorization Redirect Metadata Cache (ms): 345 <-----Should be incrementing RTT saved by Content Refresh Check Metadata Cache (ms): 44987 <-----Should be incrementing Total Time Saved by Fast Connection Use (ms): 456 Total Locally Served Redirect Responses: 453 <-----Should be incrementing Total Locally Served Unauthorized Responses: 56 <-----Should be incrementing Total Locally Served Conditional Responses: 4932 <-----Should be incrementing Total Remotely Served Redirect Responses: 0 Total Remotely Served Unauthorized Responses: 0 Total Remotely Served Conditional Responses: 1 Total Requests with URL Longer than 255 Characters: 0 Total Requests with HTTP Pipelining: 0 Total Transactions Handled: 2 <-----Total number of HTTP transactions processed Total Server Compression Suppression: 1 <-----Total number of Accept-Encoding removed Total Requests Requiring Server Content-Revalidation: 0 Total Responses not to be Cached: 0 Total Connections Expecting Authentication: 0 Total Connections with Unsupported HTTP Requests: 0 Total Connections with Unsupported HTTP Responses: 0 Total Hints Sent to DRE Layer to Flush Data: 2 Total Hints Sent to DRE Layer to Skip LZ: 0 Total Hints Sent to DRE Layer to Skip Header Information: 1
If the Total Time Saved counter in the output above is not incrementing or is quite small, it indicates that the HTTP AO is not providing much benefit. If the Total Time Saved by one of the three metadata caches is not incrementing or is quite small, it indicates that the corresponding metadata cache is not providing much benefit.
The Total Server Compression Suppression counter indicates how many times the Accept-Encoding header has been removed, in an attempt to provide a better compression by the WAE device. The Total Hints Sent to DRE Layer counters indicate how many times each of the DRE hints (Flush Data, Skip LZ, Skip Header) has been issued to the DRE module, in an attempt to better compress the data.
To view similar information from the Central Manager in version 4.2.1 and later, choose the WAE device, then choose Monitor > Acceleration > HTTP Acceleration Report and choose the Details tab to see the following charts:
- HTTP Response Time Savings (fast connection reuse, redirect, conditional, and unauthorized cached)
- HTTP Optimization Count (number of times each of the above optimizations has been applied)
- HTTP Optimization Techniques (for all HTTP optimizations, including metadata caches, connection reuse, DRE hints and suppress-server-encoding)
To see debugging information on the HTTP header parsing and error conditions, use the show statistics accelerator http counters command (in 4.2.1 and later) to determine the following:
- Number of 301, 304 and 401 responses cached
- Number of HTTP headers, version and methods
- Reasons for HTTP responses not being cached
- Total number of HTTP responses being cached
- Reasons for HTTP requests not being served from the local cache
Use the show statistics connection optimized http command to check that the WAAS device is establishing optimized HTTP connections. Verify that an "H" appears in the Accel column for HTTP connections, which indicates that the HTTP AO was used, as follows:
WAE674# sh stat conn opt http Current Active Optimized Flows: 2 Current Active Optimized TCP Plus Flows: 2 Current Active Optimized TCP Only Flows: 0 Current Active Optimized TCP Preposition Flows: 0 Current Active Auto-Discovery Flows: 0 Current Active Pass-Through Flows: 0 Historical Flows: 100 D:DRE,L:LZ,T:TCP Optimization, A:AOIM,C:CIFS,E:EPM,G:GENERIC,H:HTTP,M:MAPI,N:NFS,S:SSL,V:VIDEO ConnID Source IP:Port Dest IP:Port PeerID Accel 5929 10.10.10.10:3446 10.10.100.100:80 00:14:5e:84:24:5f THDL <-------Look for "H"
You can check connection statistics for closed connections by using the show statistics connection closed http command.
To view similar information from the Central Manager, choose the WAE device, then choose Monitor > Optimization > Connections Statistics.
- Figure 2. Connection Statistics Report with HTTP
In the Connection Statistics report, the globe icon in the Applied Policy column shows that the HTTP AO was used for a connection. (Place your cursor over an icon to see its meaning.)
You can view the HTTP connection statistics by using the show statistics connection optimized http detail command. Look for the "Fast connections" counter in the output. A positive value for this counter means that the HTTP AO benefits clients by reusing persistent connections, which reduces latency.
WAE674# show stat conn opt http detail
Connection Id: 1496
Peer Id: 00:14:5e:84:24:5f
Connection Type: EXTERNAL CLIENT
Start Time: Wed Jul 15 05:09:52 2009
Source IP Address: 10.10.10.10
Source Port Number: 1760
Destination IP Address: 10.10.100.100
Destination Port Number: 80
Application Name: Web <-----Should see Web
Classifier Name: HTTP <-----Should see HTTP
Map Name: basic
Directed Mode: FALSE
Preposition Flow: FALSE
Policy Details:
Configured: TCP_OPTIMIZE + DRE + LZ
Derived: TCP_OPTIMIZE + DRE + LZ
Peer: TCP_OPTIMIZE + DRE + LZ
Negotiated: TCP_OPTIMIZE + DRE + LZ
Applied: TCP_OPTIMIZE + DRE + LZ
Accelerator Details:
Configured: HTTP <-----Should see HTTP configured
Derived: HTTP
Applied: HTTP <-----Should see HTTP applied
Hist: None
Original Optimized
-------------------- --------------------
Bytes Read: 266 139160
Bytes Written: 82686 128
. . .
HTTP : 1496
Time Statistics were Last Reset/Cleared: Wed Jul 15
05:09:52 2009
Total Bytes Read: 3269
56367
Total Bytes Written: 3269
56367
Total Bytes Buffered: 0
0
Total Internal Bytes Read: 92
Total Internal Bytes Written: 92
Bit Flags for I/O state: 1040
Internal object pointer: 2046823200
Fast connections: 11 <-----Reused connections
. . .
Metadata Cache Content
To display the content of the three metadata caches (redirect, conditional, and unauthorized), use the show cache http-metadatacache all command. Only the full URL and the expiration (in seconds) are displayed. You can also display the content of each of the three caches separately by using the following commands:
- show cache http-metadatacache redirect-response
- show cache http-metadatacache conditional-response
- show cache http-metadatacache unauthorized-response
The typical output of the above commands is as follows:
Redirect Cache Active entries: 1, Max Entries: 1500 URL: www.abcnews.com/, Expiration (sec): 3206 Conditional Cache Active entries: 6, Max Entries: 10500 URL: www.cisco.com/web/fw/i/quicklinks-rnd-corners.gif, Expiration (sec): 3594 URL: www.cisco.com/web/fw/i/hp-sprites.gif, Expiration (sec): 3594 URL: www.cisco.com/en/US/home/images/ba-actsGreen-logo.jpg, Expiration (sec): 3594 URL: www.cisco.com/en/US/home/images/fp-eos3.jpg, Expiration (sec): 3594 URL: www.cisco.com/en/US/home/images/fp-AP541n.jpg, Expiration (sec): 3594 URL: www.cisco.com/web/fw/c/home.min.css, Expiration (sec): 3592 Unauthorized Cache Active entries: 1, Max Entries: 3000 URL: l.yimg.com/index.html, Expiration (sec): 86393
You can clear the content of the three caches with the clear cache http-metadatacache all command.
If you want to clear the content of each cache separately, you can use the following commands:
- clear cache http-metadatacache redirect-response
- clear cache http-metadatacache conditional-response
- clear cache http-metadatacache unauthorized-response
If you want to specify a URL to be deleted you can use the following command:
clear cache http-metadatacache {all|redirect|conditional|unauthorized} URL
Metadata Cache Cache-Control Behavior
For 304 responses, the metadata cache has the option to honor all Cache-Control directives (Cache-Control: no-cache, no-store, private, must-revalidate, proxy-revalidate, max-age=0, Pragma: no-cache). This option is disabled by default, which means that all 304 responses with conditional headers are cached and all requests with conditional headers can be served from the local cache. We recommend that you leave this option (cache control checks) disabled to achieve the highest benefits from the cache.
Understand that enabling the cache control checks might reduce the benefits of the metadata-cache, because some browsers or web servers might have a default option to include one cache control header in all responses in order to force revalidation of the object through the original server. This would make the metadata cache ineffective for 304 responses.
The option can be independently controlled for HTTP requests (cache lookups) and responses (cache insertions).
To enable cache control checks on HTTP 304 requests, use the following command:
WAE#no accelerator http metadatacache request-ignore-no-cache enable
This command forces the metadatacache to honor all Cache-Control directives in HTTP 304 requests.
To enable cache control checks on HTTP 304 responses, use the following command:
WAE#no accelerator http metadatacache response-ignore-no-cache enable
This command forces the metadatacache to honor all Cache-Control directives in HTTP 304 responses.
The metadata cache honors Cache-Control headers for 301 and 401 responses. If the response has any of the Cache-Control headers (no-cache, no-store, private, must-revalidate, proxy-revalidate, max-age=0, Pragma: no-cache), it is not cached.
Metadata Caching Exceptions
There are certain exceptions to what is cached. The cache insertion or lookup does not occur when the HTTP AO encounters one of the following conditions on the HTTP request/response being processed:
- Non-RFC complaint requests and responses: malformed/invalid headers, repeated headers, missing headers, unexpected body, unexpected chunked encoding
- URL size is more than 255 characters
- HTTP pipelined transactions
- WebDav methods
- HEAD method
- 301/401 responses with cookie headers
- 301 responses with a total header length of more than 768 bytes
- 401 responses with a total header length of more than 384 bytes
- 401 responses with a chunked body
- 401 responses with unsupported authentication method (supported methods include: Basic, NTLM, Negotiate, Kerberos, Digest, Oauth)
- Partial HTTP header (header split) available for processing
HTTP AO Logging
The following log files are available for troubleshooting HTTP AO issues:
- Transaction log files: /local1/logs/tfo/working.log (and /local1/logs/tfo/tfo_log_*.txt)
- Debug log files: /local1/errorlog/httpao-errorlog.current (and httpao-errorlog.*)
For easier debugging, you should first set up an ACL to restrict packets to one host.
WAE674(config)# ip access-list extended 150 permit tcp host 10.10.10.10 any WAE674(config)# ip access-list extended 150 permit tcp any host 10.10.10.10
To enable transaction logging, use the transaction-logs configuration command as follows:
wae(config)# transaction-logs flow enable wae(config)# transaction-logs flow access-list 150
You can view the end of a transaction log file by using the type-tail command as follows:
wae# type-tail tfo_log_10.10.11.230_20090715_130000.txt Wed Jul 15 13:37:00 2009 :1529 :10.10.10.10 :2004 :10.10.100.100 :80 :OT :END :EXTERNAL CLIENT :(HTTP) :0 :0 :107 :117 Wed Jul 15 13:37:00 2009 :1529 :10.10.10.10 :1880 :10.10.100.100 :80 :SODRE :END :14357 :8406 :2181 :2761 :0 Wed Jul 15 13:38:19 2009 :1533 :10.10.10.10 :2008 :10.10.100.101 :135 :OT :START :EXTERNAL CLIENT :00.14.5e.84.24.5f :basic :Other :MS-EndPointMapper :F :(TFO) (TFO) (TFO) (TFO) (TFO) :<None> :(EPM) (EPM) (EPM) :<None> :<None> :0 :120 Wed Jul 15 13:38:19 2009 :1534 :10.10.10.10 :2009 :10.10.100.101 :1025 :OT :START :EXTERNAL CLIENT :00.14.5e.84.24.5f :uuide3514235-4b06-11d1-ab04-00c04fc2dcd2
To set up and enable debug logging of the HTTP AO, use the following commands.
NOTE: Debug logging is CPU intensive and can generate a large amount of output. Use it judiciously and sparingly in a production environment.
You can enable detailed logging to the disk:
WAE674(config)# logging disk enable WAE674(config)# logging disk priority detail
You can enable debug logging for connections in the ACL:
WAE674# debug connection access-list 150
The options for HTTP AO debugging (on 4.2.1 and later) are as follows:
WAE674# debug accelerator http ?
all enable all HTTP accelerator debugs
bypass-list enable HTTP bypass-list debugs
cli enable HTTP CLI debugs
conditional-response enable HTTP metadatacache conditional (304) response
debugs
connection enable HTTP connection debugs
dre-hints enable HTTP dre-hints debugs
metadatacache enable HTTP metadatacache debugs
prefetch enable HTTP prefetch debugs
redirect-response enable HTTP metadatacache redirect (301) response
debugs
shell enable HTTP shell debugs
suppress-server-encoding enable HTTP suppress-server-encoding debugs
transaction enable HTTP transaction debugs
unauthorized-response enable HTTP auth-optimization debugs bugs
You can enable debug logging for HTTP connections and then display the end of the debug error log as follows:
WAE674# debug accelerator http connection WAE674# type-tail errorlog/httpao-errorlog.current follow
