Tracing Drupal's uncacheable pages with Compass

There's one string I search for before anything else when a Drupal site starts feeling slow:

UNCACHEABLE (poor cacheability)

It's the value Drupal's dynamic page cache writes into the X-Drupal-Dynamic-Cache response header when it decides a page can't be cached. On the Skpr hosting platform we bubble that header up into our Nginx logs, so we can track it per request and over time.

Here's the kind of line that can ruin your day:

{
  "request": "GET /redacted HTTP/1.1",
  "request_id": "Root=x-xxxxx-xxxxxxxxxxxxxxxxxxxx",
  "request_method": "GET",
  "request_time": "2.219",
  "upstream_http_x_drupal_dynamic_cache": "UNCACHEABLE (poor cacheability)"
}

2.2 seconds. Every time. Uncacheable.

Let me tell you why.

Caching has layers

On a typical Skpr site, a request has to miss two of them before anything expensive happens.

1. The edge cache (CloudFront). Most traffic never gets past here.
2. Drupal's own caches. Dynamic page cache and other caching mechanisms catch what the edge doesn't.

Miss both and there's nothing left to fall back on. Drupal computes the entire response from scratch.

That second layer does more work than it gets credit for. Someone appends a tracking query string, an odd path shows up, a crawler wanders through. The edge has nothing for any of those, but Drupal does, so the response is still fast. Defence in depth. The full rebuild is meant to be the rare case, not the routine one.

The awkward middle

UNCACHEABLE (poor cacheability) means Drupal won't cache the response internally, but it still hands the edge enough to cache it. From the outside everything looks fine. The page is in the CDN, the response is fast, the graphs are flat.

The problem is what a miss costs. Normally an edge miss is cheap, because Drupal answers from its own page cache and the expensive build already happened once. With poor cacheability there's nothing in the middle. Every miss is a full rebuild. Two seconds of PHP (maybe more!), from scratch, every time.

And misses aren't a misconfiguration. They're the normal operating state of a CDN. You deploy and purge. An editor saves a node and invalidates a tag that's used on half the site. A new region starts cold. A crawler works through a long tail of URLs no human has requested this month.

None of this shows up in uptime checks or your edge hit ratio. The only thing that flags it is a header Drupal sets on the way out.

Where it comes from

The header gets set in one place, DynamicPageCacheSubscriber:

// core/modules/dynamic_page_cache/src/EventSubscriber/DynamicPageCacheSubscriber.php:198

// There's no work left to be done if this is an uncacheable response.
if (!$this->shouldCacheResponse($response)) {
  // The response is uncacheable, mark it as such.
  $response->headers->set(self::HEADER, 'UNCACHEABLE (poor cacheability)');
  return;
}

shouldCacheResponse() runs a handful of checks. It rejects responses with a max-age at or below the configured threshold, responses carrying a high-cardinality cache context, and responses carrying a high-invalidation-frequency cache tag. Those are all reasonable.

// core/modules/dynamic_page_cache/src/EventSubscriber/DynamicPageCacheSubscriber.php:253

protected function shouldCacheResponse(CacheableResponseInterface $response) {
  $conditions = $this->rendererConfig['auto_placeholder_conditions'];

  // Create a new CacheableMetadata to avoid changing the response itself.
  $cacheability = CacheableMetadata::createFromObject($response->getCacheableMetadata());

  // Response's max-age is at or below the configured threshold.
  if ($cacheability->getCacheMaxAge() !== Cache::PERMANENT && $cacheability->getCacheMaxAge() <= $conditions['max-age']) {
    return FALSE;
  }

  // Optimize the contexts and let them affect the cache tags to mimic what
  // happens to the cacheability in the variation cache.
  $cacheability->addCacheableDependency($this->cacheContextsManager->convertTokensToKeys($cacheability->getCacheContexts()));
  $cacheability->setCacheContexts($this->cacheContextsManager->optimizeTokens($cacheability->getCacheContexts()));

  // Response has a high-cardinality cache context.
  if (array_intersect($cacheability->getCacheContexts(), $conditions['contexts'])) {
	return FALSE;
  }

  // Response has a high-invalidation frequency cache tag.
  if (array_intersect($cacheability->getCacheTags(), $conditions['tags'])) {
	return FALSE;
  }

  return TRUE;
}

The line I want to focus on is this one:

$cacheability = CacheableMetadata::createFromObject($response->getCacheableMetadata());

Follow createFromObject() into CacheableMetadata and you find this:

// core/lib/Drupal/Core/Cache/CacheableMetadata.php

public static function createFromObject($object) {
  if ($object instanceof CacheableDependencyInterface) {
    $meta = new static();
    $meta->cacheContexts = $object->getCacheContexts();
    $meta->cacheTags = $object->getCacheTags();
    $meta->cacheMaxAge = $object->getCacheMaxAge();
    return $meta;
  }

  // Objects that don't implement CacheableDependencyInterface must be assumed
  // to be uncacheable, so set max-age 0.
  $meta = new static();
  $meta->cacheMaxAge = 0;
  return $meta;
}

If an object doesn't implement CacheableDependencyInterface, Drupal assumes the worst and sets max-age to 0. It's completely silent.

Nothing throws. Nothing logs. No test fails unless you wrote a test that specifically looks. One component somewhere in a render tree forgets an interface, its max-age of 0 bubbles all the way up, and the entire page becomes uncacheable. The symptom shows up in production, in a header, weeks later, attached to a page that has nothing obviously wrong with it.

Finding it with Compass

We have been building cacheability detection into Compass.

Compass is our open-source telemetry system for PHP, built on eBPF, Rust and Go, which we've talked about at DrupalCon.

Our new terminal UI now provides an identifier to developers, showing which traces need to be reviewed.

Drilling into that trace shows the request timing, and (for this example) a flag: uncacheable. The panel at the bottom names the caller, tags and contexts. In this case it's the Umami language switcher block causing this page to be uncacheable.

So instead of tailing logs and guessing, you open the trace and read the name of the thing that broke it. You can do the same for cache contexts across the page, which is useful on its own for working out why a page varies more than you expected.

That's the whole idea. Turn a silent, catastrophic, hard-to-reproduce performance bug into a line item you can point at.

Where this goes next

Both the Compass extension and the tracing tool have been through review and benchmarking, and the work now is integration:

• Shipping to local development environments first, so the team can use it on real sites and tell me what's missing
• Wiring it into the Skpr CLI, with the UI to follow

In the meantime, go and grep your access logs for UNCACHEABLE. I'd be surprised if you came back empty-handed.