Cache debugging

When customizing the Cache module configuration or using an advanced caching strategy, it can be helpful to have some confirmation things are working as intended. By turning on the debugging features of the cache module, you can verify both cache and flush events.

Cache filter

The cache filter is the entry point into cache debugging. To see if an item is being cached, enable DEBUG using the Log Tools app or adjust the log4j2 configuration file. The former is a transient adjustment (resets on restart), while the latter is permanent (survives the restart). Usually, using the app is the preferred approach.

Enable filter debugging

  1. Open the Log Tools app.

  2. Go to the Log Levels tab.

  3. At the bottom of the page, enter the Logger name: info.magnolia.module.cache.filter.CacheFilter.

  4. Click Add logger config and check the entry is added to the list above at DEBUG level.

Debug requests

With debug enabled, you can begin making some test requests.

Using the travel demo as an example:

The cache behaves differently for author and public instances. For testing purposes, a public instance typically makes the most sense.

  1. Request the page http://localhost:8080/magnoliaPublic/travel.html.

  2. First request: behaviour=store

    2021-04-07 06:40:09,806 DEBUG info.magnolia.module.cache.filter.CacheFilter :
Cache policy result: CachePolicyResult{behaviour=store, cacheName=defaultPageCache,
cacheKey=DefaultCacheKey{uri='/travel.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{cookiesConsent=dismiss}'},
cachedEntry=null}

  3. Second request: behaviour=useCache

    2021-04-07 06:44:22,511 DEBUG info.magnolia.module.cache.filter.CacheFilter :
Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=defaultPageCache,
cacheKey=DefaultCacheKey{uri='/travel.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{cookiesConsent=dismiss}'},
cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@bb8bd81[gzippedContent=5712 bytes,plainContent=25141 bytes,characterEncoding=UTF-8,contentType=text/html,lastModificationTime=1617792009808,originalUrl=http://localhost:8080/dx-core-webapp/travel.html,serializableHeadersBackingList=<null>,statusCode=200,timeToLiveInSeconds=-1]}

Cache policy result

With DEBUG enabled, the CachePolicyResult is printed to the log.

Parameter Description

behaviour

One of three values:

  • bypass: Skips caching. This is useful for content that can’t or shouldn’t be cached.

  • useCache: Retrieves the cached item from the cache and streams it to the client.

  • store: Stores the response in the cache for future use.

cacheName

The name of the cache being used to store the result. The defaultPageCache is essentially the fallback cache store for requests that don’t use site-aware caching.

cacheKey

The default cache key implementation is based on the URI, server name, parameters, and request headers.

Since the server name is likely to change from server to server, copying cached items around doesn’t prevent generating cache entries.
Parameter Description

uri

The URI of the requested resource. This is the key used by the cache for storage and retrieval of the value stored by the cache. The value is the HTML generated during rendering or the binary data of the requested resource.

serverName

The requested server.

locale

The requested locale.

channel

The requested channel. Typical values are all, desktop, and mobile. Sometimes, it can be "unresolved" if the MultiChannelFilter can’t determine the channel.

params

Any parameters passed as part of the request.

secure

Indicates if the request was made over a secure connection.

method

The request method. POST, GET, PUT, DELETE, and so on.

additionalAttributes

Any other attributes passed as part of the request.

cachedEntry

Cache entry keeping the content in memory. Stores a gzipped and non-gzipped version.

Parameter Description

gzippedContent

Length of the gzipped content.

plainContent

Length of the plain content.

characterEncoding

Character encoding for the stored content.

contentType

Type of content being stored.

lastModificationTime

Last time the content was modified.

originalUrl

Original requesting URL.

serializableHeadersBackingList

List of serializable headers associated with the request.

statusCode

HTTP status code.

timeToLiveInSeconds

Time for how long the content should be valid. -1 indicates forever.

Flush events

Cache flush events can happen:

  • When publishing events complete, that is, when content is published successfully from the author to the public instance. This is the default behavior.

  • When content is updated. When debugging a custom cache configuration, it can be helpful to have these flushes indicated in the log file. For example, when using advance caching strategies like serving old content while recaching or eager recaching.

To enable the TRACE level logging for flush events, use the Log Tools app or adjust the log4j2 configuration file.

Enable flush debugging

With flush debugging enabled, you see the flush event indicated in the log. This also provides the name of the cache being flushed if you use multiple caches.

  1. Open the Log Tools app.

  2. Go to the Log Levels tab.

  3. At the bottom of the page, enter the Logger name: info.magnolia.module.cache.

  4. Click Add logger config and check the entry is added to the list above at ALL level.

Site-aware flush events

Using the Advanced Cache module you can configure workspaces to be site-aware. To do so, you must configure:

Enable site-aware flush debugging

When publishing completes

By default, site-aware flush events happen when publishing successfully completes.

The INFO log level is enabled by default.

Example
INFO  info.magnolia.publishing.receiver.operation.jcr.JcrPublicationOperation 30.01.2024 13:09:27 -- About to update content under path [/travel].
INFO  info.magnolia.publishing.transactional.receiver.operation.jcr.JcrTransactionPublicationOperation 30.01.2024 13:09:27 -- 35 User superuser successfully published website:/travel on magnolia-dev-webapp-1.0-SNAPSHOT.
INFO  info.magnolia.module.cache.flushpolicy.FlushAllFromPublishingEventPolicy 30.01.2024 13:09:27 -- Invalidate cache 'defaultPageCache' after 'publish' operation.
INFO  info.magnolia.module.cache.flushpolicy.FlushAllFromPublishingEventPolicy 30.01.2024 13:09:27 -- Invalidate cache 'uuid-key-mapping' after 'publish' operation.
INFO  info.magnolia.module.advancedcache.SiteAwareFlushFromPublishingEventPolicy 30.01.2024 13:09:27 -- Invalidate cache 'travel' after 'publish' operation.

When content is updated

You can choose to trigger site-aware flush events when content changes instead. To enable the TRACE level logging for flush events, use the Log Tools app or adjust the log4j2 configuration file.

With flush debugging enabled, you see the flush event indicated in the log. This also provides the name of the cache being flushed if you use multiple caches.

  1. Open the Log Tools app.

  2. Go to the Log Levels tab.

  3. At the bottom of the page, enter the Logger name: info.magnolia.module.advancedcache.

  4. Click Add logger config and check the entry is added to the list above at ALL level.

    Example
    INFO  ing.receiver.operation.jcr.JcrPublicationOperation: About to update content under path [/travel].
INFO  r.operation.jcr.JcrTransactionPublicationOperation: 364 User superuser successfully published website:/travel on magnoliaPublic.
TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: sportstation
TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: travel
TRACE info.magnolia.module.cache.FlushAllListeningPolicy: Cache flushed: uuid-key-mapping
TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: defaultPageCache

INFO  ing.receiver.operation.jcr.JcrPublicationOperation: About to update content under path [/travel/tour-type].
INFO  r.operation.jcr.JcrTransactionPublicationOperation: 360 User superuser successfully published website:/travel/tour-type on magnoliaPublic.
TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: travel
TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: defaultPageCache
TRACE info.magnolia.module.cache.FlushAllListeningPolicy: Cache flushed: uuid-key-mapping
Feedback

DX Core

×

Location

This widget lets you know where you are on the docs site.

You are currently perusing through the Performance tuning guide docs.

Main doc sections

DX Core Headless PaaS Legacy Cloud Incubator modules