Performance Tuning, Logging & Troubleshooting (Failed Request Tracing)

IIS In Depth

Chapter 9 · Performance Tuning, Logging & Troubleshooting (Failed Request Tracing)

Web Servers Fundamentals Chapter 9 named Dynamic/Static Content Compression and Output Caching briefly, comparatively. This chapter goes deep on both, on real logging configuration, and — finally — on Failed Request Tracing, the tool Chapters 2, 5, and 8 each pointed forward to as the definitive way to turn a confusing failure into an actual root cause.

Static vs. Dynamic Compression, and IIS's Own CPU Throttle

<httpCompression dynamicCompressionDisableCpuUsage="90" dynamicCompressionEnableCpuUsage="70"> </httpCompression> <urlCompression doStaticCompression="true" doDynamicCompression="true" />

Static compression compresses a static file once and caches the compressed copy on disk, serving that cached copy for every subsequent request — genuinely cheap, since the CPU cost is paid exactly once no matter how many times the file is requested afterward. Dynamic compression compresses generated, per-request content fresh every single time, since the content itself is different on each request — a real, ongoing CPU cost that scales directly with request volume. IIS has a genuinely distinctive safeguard here that neither Apache nor Nginx has built in the same way: dynamicCompressionDisableCpuUsage automatically turns off dynamic compression once server CPU usage crosses that threshold, and dynamicCompressionEnableCpuUsage turns it back on once usage drops below the lower one — an adaptive mechanism that trades away some bandwidth savings under real load rather than letting compression itself become the thing that overloads the server.

Kernel-Mode Output Caching vs. User-Mode Caching

Web Servers Fundamentals' own comparative Output Caching mention didn't distinguish these two — but the difference is substantial. IIS's kernel-mode cache lives inside http.sys, the kernel driver that receives every incoming HTTP request before it ever reaches user-mode code at all. A cache hit there is served directly by the kernel driver itself — the IIS worker process (w3wp.exe) never even wakes up for that request, which is why kernel-mode cache hits are dramatically cheaper than any user-mode alternative. The user-mode output cache (system.webServer/caching) is the fallback for content that can't be kernel-cached at all — it still requires the worker process to run, just skipping the actual content-generation step on a cache hit.

<caching> <profiles> <add extension=".aspx" policy="CacheForTimePeriod" kernelCachePolicy="CacheForTimePeriod" duration="00:05:00" /> </profiles> </caching>
Certain modules silently disable kernel-mode caching for their own content
Kernel-mode caching only works for content http.sys itself can safely serve without any user-mode involvement — which means any response that could legitimately vary in a way the kernel driver can't evaluate on its own is ineligible. In practice, this includes content going through Chapter 6's URL Rewrite rules (the response depends on rule logic that only runs in user mode) and anything requiring authentication beyond anonymous access (Chapter 8) — Windows Authentication's own per-user response can't be safely served from a single shared kernel-mode cache entry. Content that "should" be cached and isn't, with no error anywhere, is very often explained by one of these two features being active on the same path.

Logging: W3C Extended Format and Rollover

<logFile logFormat="W3C" period="Daily" logExtFileFlags="Date, Time, ClientIP, UserName, Method, UriStem, UriQuery, HttpStatus, TimeTaken" />

The W3C Extended Log File Format is IIS's own default, configurable field-by-field — time-taken (request duration in milliseconds) is particularly useful paired with Failed Request Tracing below, since a slow-but-successful request often needs a different diagnosis than an outright failure. Log files land under %SystemDrive%\inetpub\logs\LogFiles by default, one subfolder per site, rolling over on the configured period (Hourly/Daily/Weekly/Monthly) or once a file reaches truncateSize. For a multi-server web farm, Centralized Binary Logging is a real alternative worth knowing about: a single shared binary log file across every server rather than separate per-server text logs, avoiding the need to reconcile logs from several machines by hand — a genuinely different tradeoff from either Apache's or Nginx's own typically per-server text log files.

Failed Request Tracing: The Forward-Referenced Payoff

<tracing> <traceFailedRequests> <add path="*"> <traceAreas> <add provider="ASP" verbosity="Verbose" /> <add provider="WWW Server" verbosity="Verbose" /> </traceAreas> <failureDefinitions statusCodes="401,403,500-599" timeTaken="00:00:10" /> </add> </traceFailedRequests> </tracing>

This is the tool Chapter 2 named as the way to find out why a pool kept crash-looping into Rapid-Fail Protection, that Chapter 5 named as scoped per application, and that Chapter 8 named as the way to turn "the request got a 401/403" into an actual cause. failureDefinitions tells IIS exactly which requests are worth capturing — here, a specific set of status codes or any request taking over 10 seconds — rather than tracing every single request, which would be prohibitively expensive and fill disk space fast. Once a matching request occurs, IIS writes a detailed XML file recording every pipeline event and module notification the request passed through, each with its own precise timestamp — the exact module that returned 401, the exact point a request crossed the 10-second threshold, or the exact point in the pipeline where a worker process crash actually occurred. Opened in a browser (the generated XML ships with its own XSL stylesheet), this turns a bare status code or a Rapid-Fail Protection 503 into a genuine, attributable root cause — module by module, event by event.

Where this closes the loop on this course
Every forward reference this course has made — Chapter 2's crash-looping pool, Chapter 5's per-application troubleshooting, Chapter 8's authentication/filtering denials — resolves here. Failed Request Tracing is genuinely the diagnostic capstone underneath everything covered so far, which is exactly why the capstone in Chapter 10 uses it as the final verification step for the deployment it builds.
Tracing everything, always, fills a disk
A path="*" rule with broad failureDefinitions left enabled indefinitely on a busy production site can generate a very large volume of XML trace files, since every single matching request produces its own file. Scoping failureDefinitions tightly (specific status codes, a meaningful timeTaken threshold) and disabling the rule once a specific investigation is done is the practical approach — not leaving broad tracing permanently active "just in case."

Hands-On Exercises

Exercise 1

Explain, in your own words, why a kernel-mode output cache hit is significantly cheaper than a user-mode output cache hit, in terms of what actually has to run to serve the response.

📄 View solution
Exercise 2

A page is configured with a kernel-mode caching profile, but an administrator notices via logging that every single request still reaches the application code — no cache hits are occurring at all. The same site also has a URL Rewrite rule active on that exact path. Explain the most likely reason kernel-mode caching isn't working here.

📄 View solution
Exercise 3

Referring back to Chapter 2's Rapid-Fail Protection scenario (a pool repeatedly crashing and going offline), explain specifically what Failed Request Tracing would capture that the bare 503 status code and Chapter 2's own recycling settings never could, and what failureDefinitions configuration would be appropriate to actually capture it.

📄 View solution

Chapter 9 Quick Reference

  • Static compression — cached once, cheap forever; Dynamic compression — recomputed per request, real ongoing CPU cost
  • IIS auto-throttles dynamic compression via dynamicCompressionDisableCpuUsage/...EnableCpuUsage — a genuine adaptive safeguard neither Apache nor Nginx has built in the same way
  • Kernel-mode caching (http.sys) serves a hit without ever waking the worker process — far cheaper than user-mode caching, which still requires the worker process to run
  • URL Rewrite rules and non-anonymous authentication both silently disable kernel-mode caching eligibility for affected content
  • W3C Extended logging — configurable fields, rollover by period or size; Centralized Binary Logging for web farms avoids per-server log reconciliation
  • Failed Request Tracing — scoped by failureDefinitions (status codes, time taken), captures every pipeline event/module notification for a matching request as a browsable XML file — the payoff for every troubleshooting forward-reference earlier in this course
  • Scope tracing tightly and disable it after use — broad, permanent tracing on a busy site fills disk space fast