IIS Logging and Log Analysis on a Windows VPS: Finding Slow Requests and Errors

IIS logs are the cheapest source of truth on a Windows server: plain text, written by the kernel-mode HTTP driver, and free to collect. They are also where most operators stop, because a folder of u_ex261101.log files is not analysis. The difference between a log directory and a working baseline is choosing the right W3C fields, rolling files on a boundary you can reason about, and running two or three queries that turn 200 MB of text into a list of slow URLs. This walkthrough does that on a small Windows VPS running IIS where the log volume and the disk are both finite.

W3C field selection: what to log and what to skip

IIS logs W3C extended format with 24 selectable fields. The default set counts traffic and says nothing about latency, so open IIS Manager, select the site, open Logging and click Select Fields. Enable time-taken, sc-status, sc-substatus, sc-win32-status, cs-method, cs-uri-stem, cs-uri-query and cs(User-Agent). Those eight plus the date and time give you everything needed to find slow requests and errors.

Leave cs(Cookie) and cs(Referer) off. Cookies add 200-600 bytes per line on a session-heavy site and inflate the log by a third. time-taken is in milliseconds by default; on IIS 8.5 and later switch Logging to “Time” mode in bytes for a decimal value that sorts cleanly.

Log rollover, retention and the disk they eat

Daily rollover is the default and right for most sites. Above 50,000 requests per day, go hourly: a 200 MB daily file is slow to search. Site-level truncation limits stop a runaway loop writing 30 GB before anyone notices.

Estimate first: a request line is 180-260 bytes with default fields and 350-450 with query string, user agent and latency, so 10,000 requests per day is about 300 MB a month. Delete logs older than 30 days from Task Scheduler with forfiles /p C:\inetpub\logs\LogFiles /s /m *.log /d -30 /c "cmd /c del @path".

Querying with PowerShell before installing anything

Select-String gets you surprisingly far on a single day file, and it is already installed. It is best for text matching – counting requests to a path, finding a user agent – but it cannot do a numeric comparison on time-taken because that field is the last one on the line and string sorting puts “900” after “12000”. Split the line and cast instead.

The reliable one-liner: Get-Content .\u_ex261101.log | Select-Object -Skip 4 | ForEach-Object { $f = $_ -split ' '; [pscustomobject]@{ T=[int]$f[-1]; U=$f[5]; S=$f[8] } } | Where-Object { $_.T -gt 5000 } | Sort-Object T -Descending | Select-Object -First 40. Skip the four header lines, split, cast, filter. That produces the 40 worst offenders with their URL stems and status codes in about four seconds for a 50 MB file.

Log Parser Studio for grouped analysis

Log Parser Studio is a free GUI over the Log Parser 2.2 engine, and it comes with built-in query templates: slowest pages, top error URLs, requests by status code per hour. Point it at the log folder, pick the IIS W3C input format, and run the “IIS – Top 25 slowest pages” template; it reads many files per query without loading them into memory.

A typical query groups by cs-uri-stem and averages time-taken while counting hits, so one slow endpoint with 50 hits does not get buried under a page that took 9 seconds once: SELECT TOP 50 cs-uri-stem, COUNT(*) AS Hits, AVG(time-taken) AS AvgMs, MAX(time-taken) AS MaxMs FROM *.log WHERE time-taken > 1000 GROUP BY cs-uri-stem ORDER BY AvgMs DESC. Run the same query against a quiet week and a busy week and compare the averages, not the maximums.

Correlating time-taken with app pool recycles

A latency spike with no code change and no traffic change is usually a recycle, and the recycle is usually caused by something other than the 1740-minute default. Memory limit, private bytes limit, or a config file change dropped into bin all trigger one. Recycling pauses request processing for a few seconds while the new worker starts, and any request already in flight is logged with a time-taken that includes the wait or with a 503 if the rapid-fail protection kicked in. Compare the timestamp of the slow traffic with the Application event log entry WAS event ID 5076 or the System log WAS 5009.

Look for the shape rather than the event. A recycle produces a narrow band of slow requests, typically a 3-8 second spike on all endpoints at once, followed by normal times. A slow database produces a spike only on pages that query it. A slow disk or memory pressure produces slow times that rise gradually through the day and drop after a recycle. Set Idle Time-out to 0 and prefer a scheduled recycle at a fixed time over the default 1740-minute interval, so the spike lands where you can see it rather than in the middle of a customer order.

Building an HTTP status baseline

What matters is the 5xx ratio per endpoint per hour, not the absolute count. A baseline query groups by status code and URL stem per day and stores the result as CSV; a week of those lets you alert on change rather than a fixed threshold. A healthy site sits near 92-97 percent 200s, 1-2 percent 404s from bots and favicon misses, and under 0.3 percent 5xx.

Read sc-win32-status too. A 500 with win32 status 64 is a client reset, not your bug; 995 is a cancelled completion, usually a proxy timeout; a 401 with substatus 2 is a Windows auth handshake. Counting 500s without substatus means chasing phantom incidents.

Where verbose logging stops being worth it

Above roughly 200 requests per second, logging costs real disk writes that compete with the app. Log only errors at the logging layer, keep one sampled week for trends, and let a reverse proxy or CDN handle request-level detail.

The same rule applies to a VPS that is short on disk. If you must choose between 30 days of logs and 10 GB of free space, keep the logs but compress them nightly; the files compress 8:1 to 12:1 and a plain NTFS compressed folder costs almost nothing to read back. Whatever you choose, write the retention rule down, because nobody remembers why W3SVC3 stopped producing files six months later.

When to switch to failed request tracing

Logs say a request was slow but not where in the pipeline it spent the time. Failed Request Tracing captures each module’s entry and exit, authentication, rewrite rules and handler execution as XML for one request. Enable it per site with a rule for status codes 500-599 plus a time-taken threshold of 10,000 ms, put the directory on a different drive from the logs, and cap total files at 200.

Turn it on for the hour you need and off afterwards; a bot hammering a missing page can fill a disk in a day. On a small Windows VPS with a single data disk, the pragmatic split is: W3C logs always on with daily rollover, FRT on demand with a 1 GB cap, and the two to three queries from this guide saved as a script you can rerun after every deploy.

The five-minute weekly routine

Once fields and rollover are set the routine is small: slowest-URL query for seven days, diff the top twenty against last week, 5xx ratio per endpoint, confirm retention deletes files, compare volume to bandwidth. Four numbers, one command each.

Anything that shows up gets a failed-request trace attached to the ticket before anyone restarts the app pool, because restarting first destroys the evidence.

Leave a Comment