Six OOM-kills and a comment that lied

The symptom¶

Bursty, non-reproducible, and always somebody else's code

The service publishes video metadata. One of its jobs is licence promotion: when an episode finishes playing, a message arrives and the episode's provisional broadcast licences are promoted to live ones, which cascades into sibling episodes, seasons and series.

Under bursts of promotions the container walked up to the memory ceiling and was killed by the platform. It happened six times over eight days. Operations that should take under a second took minutes — a measured worst case of 6 minutes 27 seconds for a single request.

What the heap actually contained¶

A process dump settled in one table what three weeks of reasoning had not

The service runs as a single task on AWS Fargate, which gives you no host to log into. Getting a CPU trace and a heap dump out of a container that dies only when it misbehaves was most of the work: a dotnet-monitor sidecar sharing a volume with the app container, the app started with DOTNET_DiagnosticPorts, collection rules triggering dotnet-trace and dotnet-dump, and the artefacts pushed straight to object storage because a 34 GB file is not coming back through a shell. The sidecar took six separate fixes before it produced anything — starting with the fact that it defaults to Connect mode, which does not support collection rules at all.

Once we had the dump, the answer was not subtle. The dump file was 34.5 GB. SOS reported 31,536,395,863 bytes in the managed GC heap, holding 423,555,895 objects at capture time. Over half of that heap was a single namespace.

That single row is the whole incident in one number. We were asking for that adapter on a hot path, once per lookup, and the scratch state was accumulating faster than the collector retired it.

Two fixes that did not work¶

Both were evidence-led. Both were wrong about the dominant cost.

This is the part worth keeping, because being wrong twice is how the dominant cost was isolated.

Attempt one: move the aggregate rebuild off the publish thread

One promotion triggered 1+N publishes, each synchronously rebuilding whole season and series models — roughly O(N²) per promotion in episodes-per-season. A background dispatch queue with per-node lanes fixed the crash mechanism: lock errors went to zero and the lock-related restarts stopped. It did not reduce the cost. A burst still reached 97–99% CPU and 90%+ memory.

Attempt two: reorder so the indexed lookup runs first

The code had two ways to resolve a node by identifier: an XPath query over the content tree, and a lookup against the search index. It tried XPath first. So we reordered: try the index, fall back to XPath only on a miss. Latency fell from 92 s to single digits within minutes — and then a second OOM arrived under a bigger burst. The fresh trace showed XPath dominating more than before, at 41.57% of CPU.

That result is the most useful thing in this investigation, so it is worth doing the arithmetic. Let c_e and c_x be the per-call costs of the indexed and XPath lookups, and p the probability the index misses. Under index-first ordering, expected cost per resolution is:

E[c] = c_e + p · c_x

The sampled trace estimates the aggregate contribution of both terms over the capture window: 41.57% of CPU samples in the XPath call against 0.09% in the indexed one. So p · c_x / c_e ≈ 462, and the XPath term accounted for 99.78% of the cost of resolving content by identifier even with the index tried first.

There is a second, sharper reason reordering could not work, and it is easy to miss: the fallback was invoked only when the indexed lookup missed. It therefore ran, essentially always, in its own worst case — the miss, where nothing can stop the tree enumeration early. The code was structured so that the expensive path was reached exclusively under the input distribution that maximises its cost.

The comment¶

Two methods, one cost warning, and it was on the wrong one

Which raises the real question: why would anyone write six call sites that prefer the expensive path? Nobody chose it on a hunch. They read the interface. Here it is as it stood, with both declarations next to each other:

public interface IContentSearcher{    /// <summary>    /// Searches published content using XPath    /// </summary>    /// <param name="xpath">XPath. e.g.: /root/mediaLibrary//series[externalSeriesId='1234']</param>    /// <returns>Content id. Null if not found</returns>    int? GetPublishedContentId(string xpath);     /// <summary>    /// Searches content based on type and a property value. As this searches through    /// non-published items too, it's more resource-intensive.    /// </summary>    /// <returns>Content id. Null if not found</returns>    int? GetContentId(string contentType, string property, string value);}

Read it as a developer picking a method. The XPath one carries no cost note at all. The indexed one carries the only performance warning in the file — “it's more resource-intensive”. On that evidence, preferring XPath is not carelessness; it is the reasonable reading of the documented contract.

Then measure them. The method with no warning: 41.57% of CPU. The method carrying the warning: 0.09%. In this workload the warning pointed in the wrong direction by a factor of roughly 500, and it did so in the most expensive possible direction — it encouraged every caller to retain the path associated with the 8.2 million navigator instances present at capture.

There is a third detail worth noticing, because it is the part that scales the damage. The XPath method's <param> tag supplies a worked example: /root/mediaLibrary//series[…]. That example uses // — the descendant axis, the very construct that makes the walk linear in the whole subtree in this unindexed implementation. So the documentation did three things at once: it omitted any cost warning from the expensive method, it put the file's only cost warning on the cheap one, and it handed every reader a copy-pasteable template of the expensive pattern.

The change¶

Three edits, no new abstractions, no new dependencies

1. Remove the XPath fallback from all six lookups. Not deprioritised — removed, then removed from the interface too, so reintroducing it is a compile error. For the content types, fields and index configuration used here, the indexed path covered the published and unpublished current content these lookups require — which the XPath query did not.

// before — XPath first, indexed lookup as the fallbackvar contentId =    ContentSearcher.GetPublishedContentId(        $"/root/{DocumentTypes.MediaLibrary}//{DocumentTypes.Series}/{DocumentTypes.Season}"      + $"/{DocumentTypes.Episode}[externalTitleId='{externalTitleId.ToLower()}']")    ?? ContentSearcher.GetContentId("episode", "externalTitleId", externalTitleId); // aftervar contentId = ContentSearcher.GetContentId(DocumentTypes.Episode, "externalTitleId", externalTitleId);

2. Replace recursive tree walks with fixed-depth traversal. A helper used Descendants() — a full recursive walk through the same navigation machinery. The content-type schema permits series to contain only clips and seasons, seasons only clips and episodes, and episodes only clips and video assets — so an episode cannot exist anywhere but exactly two levels down.

seriesPublishedContent.Descendants().Where(x => x.ContentType.Alias.InvariantEquals("episode"))seriesPublishedContent.Children.SelectMany(season => season.Children)    .Where(x => x.ContentType.Alias.InvariantEquals(DocumentTypes.Episode))

3. Delete a second, redundant walk that recomputed the most-recent-episode date the whole tree over. The same method had already materialised an episode projection at its top and was using it for two other fields; the date was derivable from that list, so the walk bought nothing.

// before — a second full recursive walk, for one datemodel.MostRecentEpisodeUpdate = GetMostRecentEpisodeUpdate(publishedContent); private DateTime GetMostRecentEpisodeUpdate(IPublishedContent publishedContent){    var episodes = publishedContent.Descendants()        .Where(d => d.ContentType.Alias == "episode")        .ToList();     if (!episodes.Any())        return DateTime.MinValue;     return episodes.Max(e => e.UpdateDate);} // after — the projection is already in hand; the helper is gonemodel.MostRecentEpisodeUpdate = DateTimeHelper.GetMaxOrDefault(DateTime.MinValue, episodes.Select(e => e.UpdateDate));

The framework is moving the same way independently: the XPath lookup API is marked [Obsolete] in v13 and XPath traversal is removed entirely in v14+, with “use search methods instead” as the stated guidance.

Why it is asymptotically better, not just faster¶

Two data structures, one question, and a gap that is structural

Two structures were available for the same question — find the node whose property p equals v. One is an ordered tree with no secondary index; the other is an inverted index built for exactly this.

In XPath, // expands to a descendant-or-self step, producing candidates from the subtree to which the predicate is then applied. The specification fixes that meaning, not a physical execution strategy — but in this path there was no secondary index for the property predicate, so a miss required examining the whole candidate subtree. The framework drives a navigator cursor over the in-memory tree — pointer-chasing, with no index to consult. A miss is Θ(N) in the node count under the search root. The census above accounts for 2,584 of them — series, season, episode, videoAsset. The schema also permits clip nodes at three levels, which the walk enumerates and which are not counted there, so treat 2,584 as a floor rather than a total. The bound does not rest on the exact figure, only on N growing with the library.

Because the result is consumed with FirstOrDefault() over a lazy iterator, the walk terminates early on a hit, so the honest bound is best case O(1), expected N/2 visits if exactly one match is uniformly distributed in traversal order — still Θ(N), since a constant factor does not survive the notation — and worst case Θ(N).

The index path has different asymptotics entirely. Examine 3.8 sits on Lucene.NET 4.8, whose term dictionary is a block-tree with a finite state transducer index held in memory. Resolving a term costs O(|t|) in the length of the term string — one FST transition per character — then a seek into the postings block and O(df) to iterate matching documents, per segment. Writing DF for the total document frequency across all S segments:

T_index = O(S · |t| + DF) versus T_walk = Θ(N)

Here DF = 1, because identifiers are unique, and |t| is bounded by the identifier format at around ten characters. There is no term proportional to scanning all N content nodes. Examine resolves the term through Lucene’s indexed structures without walking the content tree, and for this short, unique-identifier lookup the cost was effectively insensitive to catalogue size next to the linear content-tree scan. What remains is the segment count S, which merge policy keeps small rather than letting it track library size. This is not a claim that Lucene is constant-time in general: a longer term, a high document frequency, or a different query shape each reintroduce a factor that grows. It is the specific reason this lookup does not scale with the catalogue the way the tree walk does — and why the gap widens every month the catalogue grows.

Space was the term that actually killed the process

Time complexity explains the latency. It does not explain the OOM-kills, and the space behaviour is the more interesting half. Building an XmlDocument adapter per call allocates in proportion to the properties materialised into it, with no pooling or caching evident in the source path. Transient allocation of that kind is survivable; a generational collector is built for exactly that.

The heap census and the rising memory telemetry together showed that this was not harmless transient allocation. Constructing the adapter added allocation proportional to the content materialised into it, and under the burst workload those allocations were produced faster than the runtime reclaimed them, so the managed heap climbed toward the task limit. That is an observed allocation-and-reclamation imbalance, not a measured growth law: a single snapshot cannot establish that the live set scales linearly in call count.

This is the formal reason more memory was never the fix, and why both earlier attempts bought time rather than a solution. A larger heap does not remove an allocation source that outruns reclamation — it may extend the time to failure, but only at additional infrastructure cost. The underlying instability remains. Removing the allocation site changes the problem instead.

The traversal change, quantified honestly

Replacing Descendants() is a constant-factor improvement, not an asymptotic one, and it is worth resisting the temptation to overstate it. Collecting every episode of a series is inherently Θ(E) in episodes; both versions must touch all of them. What changed is the set of nodes visited: a recursive descent also visits the asset level below episodes, while the two-level version stops where episodes stop. Across the live corpus that is 2,404 nodes versus 1,838 — 23.5% fewer, the saving being precisely the 566 asset nodes. Both counts exclude clip nodes, as the census does. A 1.31× reduction in nodes visited does not explain the measured improvement, and this article should not pretend it does. The real cost was per-node, not node count: every step went through the same navigator machinery the CPU trace found dominating.

What the numbers did¶

Same environment, same live traffic, absolute windows

Resource figures below come from CloudWatch Container Insights in absolute units; latency, database calls and error classes come from New Relic. Every window is an explicit absolute range rather than a relative one, because “the last eight hours” returns a different answer every time it runs, which makes a result impossible to check.

The same window, rendered by CloudWatch itself5-minute maxima · 26 h

Promotion latency, as New Relic renders it15-minute means · 32 h

Database calls per promotion, as New Relic renders ithourly means · 32 h

Four sources, cross-checked¶

Proving the system is stable, that operations execute, and that this is not a no-op

This is the part that makes the result trustworthy rather than merely encouraging. A fix that makes a service stop doing work looks identical on a resource graph to a fix that makes it efficient: both show flat CPU and low memory. Having just deleted a code path that resolves content, the obvious failure mode was a silent no-op — lookups returning nothing, promotions skipping quietly, and the graphs looking magnificent.

No single instrument can settle that, because each is blind to what the others see. CloudWatch knows resource but not whether requests succeeded. New Relic knows transactions but not whether the search index behind them is healthy. The sidecar sees inside the process but says nothing about content. The backoffice shows content state but not load. So all four were run together, each answering a question the others structurally cannot.

One line of output for the whole system

Rather than checking four consoles by hand, the four sources were consolidated into a single polling loop, emitting one line every 150 seconds with a severity tag. Each tick carried: CPU and memory from CloudWatch; the running task count, task-definition revision and the sidecar container's status from ECS; promotion count, mean and worst latency plus a full error-class breakdown from New Relic; and the last-modified timestamp of each diagnostic artifact in S3, flagged the moment one changed.

The severity rules mattered as much as the data: warn above 60% memory or 99% CPU; alert above 80% memory, or if the task count left 1, or worst latency passed 60 seconds, or the sidecar stopped running, or a new dump fired. That last condition is the useful one — it turns a capture into a notification instead of something you discover later.

It earned its keep twice. It caught an unrelated build being deployed onto the service overnight, because the revision field changed and the sidecar row went blank. And because New Relic authenticates separately from AWS, it kept reporting through two overnight AWS session expiries that blanked every AWS-sourced field — which is precisely the argument for consolidating independent sources rather than more views of one.

The bug the telemetry could not see¶

Found by driving the real system by hand

Every metric was healthy. So the last check was to call the live endpoint directly with a real identifier — and then with the same identifier in the wrong case:

Same episode. The deleted XPath had been normalising case before querying — ToUpper() on references, ToLower() on title identifiers — and because it ran first, it silently rescued any casing. Five lookups lost that when it was removed. Worse, the endpoint maps a missing episode to HTTP 200 with Success: true. The caller sees success and never retries, so a lookup miss is an invisible dropped promotion.

The mechanism was an internal inconsistency: the index query matches case-insensitively — verified directly, both casings return the same document set — but the filter applied to its results compared ordinally, discarding a document the query had deliberately matched. One line:

.Any(v => v == value).Any(v => string.Equals(v, value, StringComparison.OrdinalIgnoreCase))

Five regression tests were added — the first this class had. They were verified to fail against the previous comparison before being accepted, because a regression test that has never failed is not evidence of anything.

Four lessons that outlive the API¶

The XPath call is deprecated. These are not.