Cache Debugging
When customizing the Cache module configuration or using an advance 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 a permanent (survives the restart). In most cases using the app is the preferred approach.
Enable filter debugging
-
Open the Log Tools app.
-
Select the subApp Log Levels.
-
At the bottom of the subApp enter the Logger name:
info.magnolia.module.cache.filter.CacheFilter
-
Click "Add logger config" and confirm the entry is added to the list above at
DEBUG
level.
Debug requests
With debug enabled you can now 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. |
-
Request the page http://localhost:8080/magnoliaPublic/travel.html.
-
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}
-
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
will be printed to the log.
Parameter | Description | ||||||||||||||||||||
---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
|
One of three values:
|
||||||||||||||||||||
|
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. |
||||||||||||||||||||
|
The default cache key implementation is based on the URI, server name, parameters and request headers.
|
||||||||||||||||||||
|
Cache entry keeping the content in memory. Stores a gzipped and non-gzipped version.
|
Flush Events
Cache flush events happen when content is updated. When debugging a custom cache configuration it can be helpful to have these flushes indicated in the log file. This is especially helpful when using advance caching strategies like serve 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 will see the flush event indicated in the log. This will also provide the name of the cache being flushed in the case you use multiple caches.
-
Open the Log Tools app.
-
Select the subApp Log Levels.
-
At the bottom of the subApp enter the Logger name:
info.magnolia.module.cache
-
Click "Add logger config" and confirm the entry is added to the list above at
ALL
level.
Site Aware
Using the Advanced Cache module it’s possible to configure workspaces to be site aware. In order for site ware caching to work properly two configurations are required.
-
The site aware flush configuration. Set in the Advanced Cache app.
-
The mapping configuration of the site definition. Set in the Site app. 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 will see the flush event indicated in the log. This will also provide the name of the cache being flushed in the case you use multiple caches.
-
Open the Log Tools app.
-
Select the
subApp
Log Levels. -
At the bottom of the subApp enter the Logger name:
info.magnolia.module.advancedcache
-
Click "Add logger config" and confirm the entry is added to the list above at
ALL
level.2021-06-08 12:48:43,164 INFO ing.receiver.operation.jcr.JcrPublicationOperation: About to update content under path [/travel]. 2021-06-08 12:48:43,387 INFO r.operation.jcr.JcrTransactionPublicationOperation: 364 User superuser successfully published website:/travel on magnoliaPublic. 2021-06-08 12:48:48,413 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: sportstation 2021-06-08 12:48:48,427 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: travel 2021-06-08 12:48:48,431 TRACE info.magnolia.module.cache.FlushAllListeningPolicy: Cache flushed: uuid-key-mapping 2021-06-08 12:48:48,434 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: defaultPageCache 2021-06-08 12:56:17,172 INFO ing.receiver.operation.jcr.JcrPublicationOperation: About to update content under path [/travel/tour-type]. 2021-06-08 12:56:17,253 INFO r.operation.jcr.JcrTransactionPublicationOperation: 360 User superuser successfully published website:/travel/tour-type on magnoliaPublic. 2021-06-08 12:56:22,410 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: travel 2021-06-08 12:56:22,410 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: defaultPageCache 2021-06-08 12:56:22,410 TRACE info.magnolia.module.cache.FlushAllListeningPolicy: Cache flushed: uuid-key-mapping