ARR 2.0 Caching Issues? A Troubleshooting Guide for Internet Information Services

Table of Contents

Internet Information Services (IIS) with Application Request Routing (ARR) offers powerful caching capabilities to improve web application performance and reduce backend server load. However, diagnosing issues when caching does not behave as expected can be challenging. This guide provides a comprehensive approach to troubleshooting ARR 2.0 caching problems, focusing on tools and techniques to trace requests and identify the root cause of caching failures. By understanding the request flow and leveraging available logging and monitoring tools, administrators can effectively diagnose and resolve issues related to caching in ARR environments.

Effective troubleshooting begins with a solid understanding of the environment and the tools at your disposal. Several essential tools can assist in tracing requests as they traverse the ARR infrastructure. These include ARR Helper, Failed Request Tracing (FREB), IIS Advanced Logging, and Network Monitor. Each tool provides a different perspective on the request lifecycle, from IIS processing to network communication, allowing for a layered approach to diagnostics.

Understanding the Architecture of the Farm

Before diving into troubleshooting, it is crucial to have a clear picture of your ARR deployment architecture. This involves understanding the topology of the ARR farm, including the number of servers involved, how routing rules are configured, and the presence of any other intermediate devices like load balancers or firewalls. Furthermore, a thorough review of the URL Rewrite rules in place is necessary, as these rules often dictate how requests are processed and forwarded, directly impacting caching behavior.

For instance, consider a simple configuration involving a single ARR server acting as a cache and reverse proxy for backend web servers. The ARR server might have disk caching enabled and specific global cache control rules defined. A typical configuration might specify a local drive for cache storage and establish rules for how long content should be cached by default if the origin server doesn’t provide explicit cache control headers. Understanding these settings is the foundational step in diagnosing any caching issue.

Disk Cache Configuration

ARR utilizes disk caching to store content locally, reducing the need to fetch it repeatedly from the origin server or parent cache nodes. The configuration specifies the location and size of the disk cache. A common setup involves allocating a dedicated drive or directory for cache storage and setting a maximum usage limit to prevent the cache from consuming excessive disk space.

Here is an example of how a disk cache might be configured within the applicationHost.config file for IIS:

<diskCache>
    <driveLocation path="E:\temp$\arrcache" maxUsage="100" />
</diskCache>

This snippet indicates that the disk cache is configured on the E:\temp$\arrcache path and has a maximum usage limit of 100 GB. Verifying this configuration is essential to ensure the cache is properly enabled and has sufficient space to operate. Issues with disk permissions, drive availability, or hitting the maximum usage limit can lead to caching failures.

Global Cache Control Rules

Global cache control rules in ARR provide a mechanism to override or set default cache behavior based on URL patterns or other request attributes. These rules are processed before the request is potentially forwarded and can significantly influence whether a piece of content is cached and for how long. Administrators can define rules to ensure content is cached even if the origin server does not send cache-friendly headers, or conversely, prevent sensitive content from being cached.

An example of a global cache control rule might look like this:

<rule name="ARR_CacheControl_DefaultCache" enabled="true" patternSyntax="Wildcard">
    <match url="*" />
    <serverVariables>
        <set name="ARR_CACHE_CONTROL_OVERRIDE" value="0,max-age=3600" />
    </serverVariables>
</rule>

This rule, named ARR_CacheControl_DefaultCache, applies to all URLs (*) and sets the ARR_CACHE_CONTROL_OVERRIDE server variable. The value 0,max-age=3600 instructs ARR to cache the response for 3600 seconds (60 minutes) if no explicit Cache-Control directive is present in the origin server’s response. This is a powerful way to enforce caching policies across the farm, but misconfigured rules can prevent content from being cached as intended.

Building a Data Gathering Plan

Troubleshooting ARR caching issues requires a systematic approach to data collection. By tracing a request through the ARR infrastructure, you can pinpoint exactly where a cache hit or miss occurs and identify potential points of failure. This section outlines a typical request flow for content that is not initially cached and highlights the tools useful at each stage.

Consider a request for content that has never been requested before or has expired from the cache. The request will traverse the ARR hierarchy, potentially involving multiple cache nodes before reaching the origin server.

  1. Request arrives at the first-tier ARR server (child node): The ARR server checks its local cache (memory and disk) for the requested content.
  2. Content is not found locally: If the content is not in the local cache, the request must be forwarded.
  3. Request is forwarded to the next-tier cache node (parent node), if configured: The child node sends the request to its designated parent cache server. The parent server then checks its local cache.
  4. Content is not found at the next tier (or subsequent tiers): If the content is not found in any cache tier, the request must eventually reach the origin server.
  5. Request is forwarded to the origin server: The last server in the chain (either an ARR node configured to route to origin or the final ARR node in a hierarchy) forwards the request to the actual web server hosting the content.
  6. Origin server responds: The origin server processes the request and sends the response back down the chain.
  7. Response is cached and returned: As the response traverses back through the ARR nodes, each node configured for caching can potentially cache the content according to its rules before sending it back to the client.

By following this flow, we can identify which server is responsible for the cache miss and where the request is being routed. This structured approach allows for targeted data collection on the relevant servers at each step.

Here’s a breakdown of which tools are most useful at each stage:

  • Requested content not found locally (on the first-tier ARR node):

    • FREB Logs: Provide detailed event tracing within the IIS pipeline, showing the cache look-up process and failure.
    • IIS Built-in Logging: Records basic information about the request, including indicators of cache hits/misses.
    • Network Monitor: Captures network traffic to verify the request arrival and subsequent forwarding.
  • Request forwarded to the next-tier cache node (parent node):

    • FREB Logs: Trace the request arrival and processing on the parent node, including its cache look-up.
    • IIS Advanced Logging module: Allows for custom logging fields, making it easier to track requests using correlation IDs.
    • IIS Built-in Logging: Provides standard request details on the parent node.
    • Network Monitor: Captures network traffic between the child and parent nodes.
  • Requested content not found at the next tier (repeat for multiple tiers): Use the same tools as step 2 on each intermediate ARR node.

  • Request forwarded to the origin server:

    • FREB Logs: Trace the request processing on the origin server if it’s also running IIS.
    • IIS Built-in Logging: Records the request and response on the origin server.
    • Network Monitor: Captures network traffic between the last ARR node and the origin server, and between the origin server and the last ARR node for the response.

This systematic plan ensures that you collect relevant data at each potential point of failure or unexpected behavior in the caching process.

Gathering the Data

With the data gathering plan in place, the next step is to execute it. Let’s look at how to use the mentioned tools to extract the necessary information at each stage of the request flow.

The Requested Content is Not Found Locally (Neither in Memory Nor on Disk)

This is often the starting point for tracing a cache miss. You need to confirm that the first-tier ARR server did indeed experience a cache miss for the specific request.

IIS Log Entry: The standard IIS logs can provide initial clues. Look at the cs-uri-query field, which ARR often populates with caching status information.

cs-uri-query: X-ARR-CACHE-HIT=0&X-ARR-LOG-ID=62a3161c-b4f5-407f-a28c-b34e48c5cda2

In this example, X-ARR-CACHE-HIT=0 clearly indicates a cache miss (0 = miss, 1 = hit). The X-ARR-LOG-ID provides a unique identifier for this specific request (62a3161c-b4f5-407f-a28c-b34e48c5cda2). This ID is crucial for correlating the request across multiple servers in the farm.

FREB Log Entry: Failed Request Tracing offers a much more detailed view of the IIS pipeline. Enable FREB for the specific URL experiencing issues. Within the FREB logs, look for events related to ARR caching.

A cache miss on the disk cache is typically indicated by the ARR_DISK_CACHE_GET_FAILED event:

Type Entry Details
Warning ARR_DISK_CACHE_GET_FAILED FilePath=”\?\C:\ARRCache\localhost\iisstart.htm.full”, ErrorCode=”The system cannot find the file specified. (0x80070002)”, IsRangeEntry=”false”, RangeOffset=”0”, RangeSegmentSize=”0”

This event explicitly states that the attempt to retrieve the file from the disk cache failed, often because the file was not found.

Once the cache miss is confirmed, FREB logs also show where the request was routed. Look for the ARR_SERVER_ROUTED event:

Type Entry Details
Info ARR_SERVER_ROUTED RoutingReason=”LoadBalancing”, Server=”W2K8WEBSERVER2”, State=”Active”, TotalRequests=”8”, FailedRequests=”0”, CurrentRequests=”1”, BytesSent=”1127”, BytesReceived=”6441379”, ResponseTime=”31351”

This entry tells you which server (W2K8WEBSERVER2 in this case) the request was forwarded to. This server is the next point of investigation.

FREB logs also show the headers added to the forwarded request. These headers are important for tracing the request on the downstream server. Look for GENERAL_SET_REQUEST_HEADER events:

Header Details
GENERAL_SET_REQUEST_HEADER HeaderName=”Max-Forwards”, HeaderValue=”10”, Replace=”true”
GENERAL_SET_REQUEST_HEADER HeaderName=”X-Forwarded-For”, HeaderValue=”127.0.0.1:62489”, Replace=”true”
GENERAL_SET_REQUEST_HEADER HeaderName=”X-ARR-SSL”, HeaderValue=”“, Replace=”true”
GENERAL_SET_REQUEST_HEADER HeaderName=”X-ARR-ClientCert”, HeaderValue=”“, Replace=”true”
GENERAL_SET_REQUEST_HEADER HeaderName=”X-ARR-LOG-ID”, HeaderValue=”fe9d20da-a571-4451-8ef3-0e7faf1a463a”, Replace=”true”

Note the X-ARR-LOG-ID header (fe9d20da-a571-4451-8ef3-0e7faf1a463a). This is the correlation ID that will allow you to uniquely identify this request on the server it is routed to.

The Request is Forwarded to the Next Tier Cache Node (Parent Node)

Now, shift your investigation to the server identified in the ARR_SERVER_ROUTED event from the previous step, which is W2K8WEBSERVER2 in our example. The goal is to confirm the request’s arrival and observe how it’s handled on this server.

FREB Logs: On the parent node (W2K8WEBSERVER2), enable FREB tracing. Look for the GENERAL_REQUEST_HEADERS event to see the headers received with the incoming request. You should find the X-ARR-LOG-ID and X-Forwarded-For headers that were added by the child node.

Header Details
GENERAL_REQUEST_HEADERS Headers=”Connection: Keep-Alive Accept: / Host: localhost Max-Forwards: 10 X-Original-URL: /iisstart.htm X-Forwarded-For: 127.0.0.1:62489 X-ARR-LOG-ID: fe9d20da-a571-4451-8ef3-0e7faf1a463a\nUser-Agent: Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.0; WOW64; .NET CLR 2.0.50727; SLCC1; Media Center PC 5.0; .NET CLR 3.5.21022; .NET CLR 3.0.04506; InfoPath.2; OfficeLiveConnector.1.3; OfficeLivePatch.0.0; .NET CLR 3.5.30729)”

Confirming the presence of X-ARR-LOG-ID: fe9d20da-a571-4451-8ef3-0e7faf1a463a verifies that the request successfully reached this server and is the same request traced on the child node. From here, you would look for ARR_DISK_CACHE_GET_FAILED or ARR_DISK_CACHE_GET_SUCCESS events on this parent node to see if it resulted in a cache hit or miss at this tier.

IIS Advanced Logging Module: This powerful module allows for highly customizable logging. You can configure it to log specific headers like X-ARR-LOG-ID and X-Forwarded-For and even filter logs to include only requests containing these headers. This makes it much easier to isolate and track requests forwarded by ARR compared to using standard IIS logs alone.

A sample configuration for Advanced Logging might include the following fields and filter:

#Software: IIS Advanced Logging Module
#Version: 1.0
#Start-Date: 2009-10-16 18:42:51.494
#Filter: ((ARRLogID isPresent ) || (xforward isPresent ))
#Fields:  date time cs-uri-stem cs-uri-query s-contentpath sc-status s-computername cs(Referer) sc-win32-status sc-bytes cs-bytes X-ARR-LOG-ID X-Forwarded-For

The resulting log entry would look something like this:

2009-10-16 18:51:29.983 /iisstart.htm - "C:\inetpub\wwwroot\iisstart.htm" 200 "W2K8WEBSERVER2" - 0 1680 219 "fe9d20da-a571-4451-8ef3-0e7faf1a463a" "127.0.0.1:62489"

This log entry provides a concise summary of the request on the parent node, including the status code (200, indicating success), the server name, and crucially, the X-ARR-LOG-ID and X-Forwarded-For values.

Network Monitor: A network trace can confirm if the request arrived at the parent server’s network interface. Filter the trace by the parent server’s IP address and port. Look for incoming HTTP requests. You can also filter by the X-ARR-LOG-ID or X-Forwarded-For header values if they are sent in clear text (which they typically are over HTTP between ARR nodes).

ARR Helper: While noted as not officially supported by Microsoft, the ARR Helper module is a third-party tool designed to simplify tracing forwarded requests. It automatically adds the X-Forwarded-For header value to the standard IIS c-ip field and the X-ARR-LOG-ID value to the cs-uri-query field. This makes it easier to see these key identifiers directly in the standard IIS logs on downstream servers without needing Advanced Logging.

Repeat Steps 1 and 2 for Multiple Levels of Cache: If your ARR setup involves more than two tiers of caching (e.g., child -> parent -> grand-parent -> origin), you must repeat the data gathering process on each intermediate ARR server. On each server, check the IIS or FREB logs for the X-ARR-CACHE-HIT status and the ARR_SERVER_ROUTED event (if it’s a miss) to determine where the request is being sent next. Use the X-ARR-LOG-ID to track the request as it hops from server to server.

Request is Forwarded to the Origin Server

Eventually, if the content is not found in any cache tier, the request will be forwarded to the origin server where the content is originally hosted. Troubleshooting at this stage focuses on verifying that the origin server received the request, processed it correctly, and returned a suitable response.

Network Monitor: Capture a network trace on the origin server’s network interface. Filter for incoming connections from the last ARR node. This trace confirms whether the request actually arrived at the origin server. Examine the request headers to see if the X-ARR-LOG-ID and X-Forwarded-For headers are present, allowing you to correlate this request with the traces from the ARR servers.

IIS Logs: If the origin server is running IIS, check its standard IIS logs. Look for log entries corresponding to the time the request was made. Pay close attention to the HTTP status code (sc-status) returned by the origin server. A 200 OK status indicates the server successfully found and served the content. Other status codes (e.g., 404 Not Found, 500 Internal Server Error) point to issues on the origin server itself, not necessarily with ARR caching. Use the X-Forwarded-For header (which might appear in the c-ip field if ARR Helper is used or in the custom fields with Advanced Logging) to identify the original client or the last ARR node.

IIS FREB Logs: If the origin server is running IIS and returned an unexpected status code (e.g., not 200 OK) or if you suspect issues in how the origin server processed the request (even if it returned 200), enable FREB tracing on the origin server. This provides a detailed view of the origin server’s processing pipeline, helping diagnose issues like application errors, permission problems, or configuration errors that prevented the content from being served correctly.

By systematically gathering data at each stage – from the initial ARR node experiencing the cache miss, through any parent cache nodes, and finally to the origin server – you build a complete picture of the request’s journey. Correlating the data using the X-ARR-LOG-ID is key to stitching together the information from different servers and identifying precisely where the caching logic or request handling went wrong.

Troubleshooting Cache Failures

Beyond tracing the request flow, specific areas within the ARR and IIS configuration should be examined when cache failures occur. These include ensuring the content is actually cacheable according to HTTP standards and ARR’s configuration, and checking the health of the disk cache.

Check Cache-Control Headers

The behavior of caching is heavily influenced by the Cache-Control headers present in the HTTP response from the origin server. Headers like Cache-Control: no-cache, Cache-Control: no-store, Cache-Control: private, or Expires directives can instruct intermediate caches (like ARR) or the client browser not to cache the content or cache it only under specific conditions.

Use tools like browser developer tools or Network Monitor to inspect the HTTP response headers received by the ARR server from the origin. If the origin server is sending headers that prevent caching (e.g., Cache-Control: no-cache), ARR will respect this unless explicitly overridden by a global cache control rule with ARR_CACHE_CONTROL_OVERRIDE. Verify these headers match your caching intentions.

Review Cache-Control Rules in ARR

ARR’s global cache control rules can override the origin server’s cache directives. Review the <globalCacheControl> section in your ARR configuration (typically in applicationHost.config). Ensure that caching is enabled globally and that any specific rules are configured correctly.

If you intend to cache content that the origin server marks as non-cacheable, verify that you have an ARR_CACHE_CONTROL_OVERRIDE rule in place with an appropriate value (e.g., 0,max-age=3600). Conversely, if certain content should not be cached, ensure there isn’t a broad rule inadvertently caching it, or add a specific rule to prevent its caching.

Verify HTTP.SYS Settings

HTTP.sys is the kernel-mode HTTP listener in Windows that handles initial request processing. It has its own response caching mechanism that operates at a very low level. While ARR caching is primarily an application-layer cache, HTTP.sys can sometimes cache static content before it even reaches ARR. However, there are specific scenarios where HTTP.sys will not cache content, such as when authentication is involved, dynamic compression is used, or specific Cache-Control headers are present.

If you are experiencing issues specifically with static content caching and suspect HTTP.sys might be involved, consult the Microsoft documentation on “Instances in which HTTP.sys doesn’t cache content”. While less directly related to ARR’s disk caching, understanding HTTP.sys behavior can help rule out lower-level caching conflicts.

Disk Cache Failures

ARR relies on the configured disk location for caching. If the drive becomes full, permissions change, or the drive experiences other issues, ARR may mark it as unhealthy and stop using it for caching. ARR logs events related to disk failures in the Windows Application event log.

Monitor the Application event log on your ARR servers for events with the source “Application Request Routing”. Look for Event ID 1006, which typically indicates a disk failure and that a drive is being marked unhealthy.

Log Name: Application
Source: Application Request Routing
Date: 11/2/2009 5:26:59 PM
Event ID: 1006
Task Category: None
Level: Warning
Keywords: Classic
User: N/A
Computer: YourARRServerName
Description: Drive with path '\\?\E:\temp$\arrcache\' is being marked unhealthy. The data contains the error code.
Event Xml: ...

If you see such events, investigate the reported drive path. Check the available disk space, permissions for the IIS worker process identity on that directory, and the general health of the drive. Clearing space, correcting permissions, or addressing underlying drive issues can resolve disk caching problems.

Further Considerations and Tips

  • Caching of Dynamic Content: ARR is primarily designed for caching static content or dynamic content with predictable responses and appropriate Cache-Control headers. Caching highly dynamic content without careful consideration can lead to users receiving stale information. Ensure your caching policies align with the nature of the content being served.
  • SSL and Caching: Caching behavior can differ for HTTP and HTTPS requests. Ensure your ARR configuration handles SSL termination and re-encryption correctly, and understand how this might interact with caching rules and headers.
  • Cache Clearing: Sometimes, the simplest solution is to clear the ARR disk cache. This can force ARR to re-fetch content from the origin. However, this should be a temporary troubleshooting step, not a solution to persistent caching issues. If content isn’t caching correctly, clearing the cache doesn’t fix the underlying problem.
  • ARR Tracing Module: In some versions or configurations, ARR might have its own specific tracing module or logging that provides insights beyond FREB, specifically focused on routing and caching decisions. Consult IIS and ARR documentation for your specific version.
  • Third-Party Modules: Be aware of any other third-party IIS modules installed, as they could potentially interfere with ARR’s processing or caching.

By combining a systematic data gathering approach with a thorough review of ARR configuration and system health, you can effectively troubleshoot and resolve most ARR 2.0 caching issues. Leveraging the detailed information provided by tools like FREB and Advanced Logging, correlated using the X-ARR-LOG-ID, is paramount in navigating the complexities of request routing and caching within an ARR farm.

Troubleshooting IIS

We hope this comprehensive guide assists you in diagnosing and resolving ARR 2.0 caching problems. What challenges have you faced with ARR caching, and what tools have you found most useful in troubleshooting? Share your experiences and questions in the comments below!

Post a Comment