This article is going to look at a little crawler I built to load a minimum of 5 pages of every page template type on our site, mainly so we could catch slow pages and any hidden 500s before our users do.
Adding it here for my own reference more than anything else, but also in case its useful to anyone else trying to get a bit more coverage out of their testing.
Why bother?
We have App Insights and we have log files, which are both great - but they only really tell you about errors you already know to look for. If a particular page template is quietly taking 30 secs to render, but nobody has actually requested that page recently, then it just doesnt show up. You dont know what you dont know.
So the idea was simple. Rather than wait for a real user (or our marketing team) to stumble onto a slow page, deliberately go and load atleast 5 examples of every single page template, time each one, and see what falls out.
Theres a second reason too, and its maybe the more useful one. Not every problem shows up as a non-200. Plenty of exceptions get caught, swallowed and quietly logged, whilst the page itself still happily renders a 200 to the user. So if you can guarantee that every template has actually been exercised in a known window of time, you can then go back over the logs for that exact period and scan for anything that was thrown silently behind the scenes.
Gathering the urls
First of all I needed a list of urls to hit. Loading the home page a couple of thousand times wouldnt tell us much - the whole point was to exercise every different template type.
Rather than go poking around in the database myself, I leant on a sitecore MCP server we have been working on. MCP - i.e. Model Context Protocol - effectively gives an AI assistant a set of tools it can call, and in our case those tools can talk directly to sitecore. So instead of writing a load of SQL, I could just ask it to pull back every page template under /sitecore/templates/Pages, and then for each template grab a handful of example published paths from the web index.
Note: it has to be the web database here, not master - if its not published, theres no front end url to load, and the crawler would just be banging its head against a 404.
That gave me around 300 urls across nearly 60 page templates to use as my seeds.
For the Sitecore MCP Server, we created our own version of community Sitecore MCP Server (https://github.com/Antonytm/mcp-sitecore-server). The existing one, is built on typescript / node stack, and we wanted something that sat on our own C# / .net stack alongside everything else we run. So rather than fork theirs, we effectively built a brand new one basing it heavily on the community version and porting the ideas across too .net. Full credit to the original - but thats a whole post in itself, which I will follow up with separately...
From there the crawler does two more things to widen the net:
- It follows links it finds on each page, up to 2 levels deep.
- It pulls in the sitemap and adds any urls its not already seen.
Crawl and time every page
The crawler itself is a small .NET8 console app. Nothing clever - it just works through the list with a small amount of concurrency (i settled on 2 or 3 at a time, any more and we were effectively load testing our own enviroment, which wasnt the idea), and records the http status code and how long each page took, first byte and total.
So that I could find the crawlers own traffic in the logs afterwards, every request goes out with a custom user agent that includes a unique run id:
User-Agent: UAT-Crawler/1.0; run={guid}
That little run id turned out to be really handy - it meant I could go back and line up a specific crawl against the data for the exact same window.
The output is just a csv, one row per page, recording the status and the timings:
url,status,ttfb_ms,total_ms/study-at-northumbria/,200,210,1804/about-us/some-slow-page/,200,15300,61240
Scanning the logs for silent errors
Once a crawl has finished I know the exact window it ran in, and I know every template has been hit atleast once. So the next step is to go and look at what the server actually logged whilst all that traffic was going through.
This is where the new sitecore mcp server earns its keep a second time. The same set of tools that pulled back the templates and example paths can also reach into the logs - so I can point it at the crawl window and just ask it to surface any exceptions or warnings, i.e. the silent ones that never made it back to the browser as an error. As mentioned above, a page can quite happily return a 200 whilst quietly logging a swallowed exception underneath, and thats exactly the kind of thing that would otherwise go un-noticed.
Between the timings from the crawler and the exceptions pulled out of the logs, you end up with a pretty decent picture of the health of every template - not just the handful that happen to get regular traffic.
What it found
The good news first - no 500s on the environment we care about. The vast majority of pages came back in a second or two, which was reassuring.
But there was a long tail. A handful of pages were taking the best part of a minute... 60 secs or so, right up against the default timeout. And the pages werent obviously related, a course page here, a search page there.
After some head scratching, the common thread turned out to be search. Every one of the slow pages was running a Solr / ContentSearch query directly on the request thread, with no timeout on it. So if Solr was slow to answer (or the query was a daft one returning thousands of results), the page just sat there waiting, sometimes for the full 60 secs, before giving up.
The not found handler was one culprit, the course search facets another, and a bit of related items logic a third. All the same shape of problem.
The fix
The fix, by enlarge, was to stop letting those searches run unbounded. We wrapped the search calls in a timeout so they give up quickly and serve a sensible fallback rather than hanging:
// give up after a few seconds and serve an empty/fallback resultvar results = ContentSearchService.RunWithTimeout(() => RunQuery(), fallback: empty, timeoutMs: 4000);
We also cached the bits that didnt need to be recalculated on every single request, and put a sensible cap back on the Solr connection timeout (it had somehow ended up set too -1, i.e. wait forever, which is never what you want).
Note: a timeout does mean that in a genuinely slow moment a user might get an empty result instead of waiting. But waiting 60 secs for a result isnt really a result either, they would have given up long before that. A fast fallback felt like the better trade off.
To be sure we hadnt changed anything visible, we captured the rendered html of a set of pages before and after the change and compared them - they came back byte for byte identical, which gave us a lot of confidence the optimisation was purely under the hood.
Summary
In this article we looked at a simple crawler that loads a cross section of every page template on the site, times each one, and tags its requests so they can be found in the logs afterwards. We used our sitecore mcp server to gather the seed urls, then let the crawler widen things out from there. It didnt find any broken pages, but it did surface a handful of slow ones that nobody had reported yet - all coming back to un-timed search queries running on the request thread.
I guess the lesson to be learnt here is that the slowest pages are often the ones nobody is looking at, so its worth going and loading them on purpose every now and then, rather than waiting for someone to complain.