-
Bug
-
Resolution: Fixed
-
Neutral
-
2.3.3
-
None
-
-
Empty show more show less
-
Maintenance 67
-
3
By adding some additional logging (MGNLCACHE-231 & MGNLADVCACHE-110) we can see that site aware caching does not seem to be functioning correctly.
Set your log4j2.xml when using the snapshots from the attached tickets:
<Logger name="info.magnolia.module.cache" level="ALL"/> <Logger name="info.magnolia.module.advancedcache" level="ALL"/>
Recreate:
- Set your instance for site aware caching.
- Fill a couple caches with requests from the travel site and sportstation site.
- Verify the cache filter is serving them from cache and the name of the cache it serves from.
- Publishing sportstation.
- Observe requests still coming from sportstation cache which we can now see is not being flushed after publication.
2020-08-11 18:41:38,094 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@54cf2a64[gzippedContent=5459 bytes,plainContent=24683 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597163944277,originalUrl=http://localhost:8080/dx-core-webapp/travel.html,timeToLiveInSeconds=-1]} 2020-08-11 18:41:38,094 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@54cf2a64[gzippedContent=5459 bytes,plainContent=24683 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597163944277,originalUrl=http://localhost:8080/dx-core-webapp/travel.html,timeToLiveInSeconds=-1] 2020-08-11 18:41:38,100 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel/main/0', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{mgnlCacheVariant={9b13970f-6b1b-451e-83fc-36cfde37f78e=0}}'}, cachedEntry=null} 2020-08-11 18:41:38,121 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [browserTtlVoter] fired 2147483647 2020-08-11 18:41:38,122 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [serverTtlVoter] fired -1 2020-08-11 18:41:38,122 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: lowestVote vote is now -1 2020-08-11 18:41:38,129 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@30b9fa97[gzippedContent=914 bytes,plainContent=4033 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList={Last-Modified=[1597164098100]},lastModificationTime=1597164098100,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/0,timeToLiveInSeconds=-1] 2020-08-11 18:41:38,131 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel/main/00', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{mgnlCacheVariant={9b13970f-6b1b-451e-83fc-36cfde37f78e=0}}'}, cachedEntry=null} 2020-08-11 18:41:38,191 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [browserTtlVoter] fired 2147483647 2020-08-11 18:41:38,191 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [serverTtlVoter] fired -1 2020-08-11 18:41:38,191 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: lowestVote vote is now -1 2020-08-11 18:41:38,194 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@2a8e275f[gzippedContent=660 bytes,plainContent=2432 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList={Last-Modified=[1597164098132]},lastModificationTime=1597164098132,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/00,timeToLiveInSeconds=-1] 2020-08-11 18:41:52,700 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=sportstation, cacheKey=DefaultCacheKey{uri='/sportstation.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@7bc42522[gzippedContent=3921 bytes,plainContent=32293 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164079373,originalUrl=http://localhost:8080/dx-core-webapp/sportstation.html,timeToLiveInSeconds=-1]} 2020-08-11 18:41:52,701 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@7bc42522[gzippedContent=3921 bytes,plainContent=32293 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164079373,originalUrl=http://localhost:8080/dx-core-webapp/sportstation.html,timeToLiveInSeconds=-1] 2020-08-11 18:42:54,621 INFO r.operation.jcr.JcrTransactionPublicationOperation: 377:1597164171492 User superuser successfully published website:/sportstation on dx-core-webapp. 2020-08-11 18:42:59,775 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: site 2020-08-11 18:42:59,776 TRACE info.magnolia.module.cache.FlushAllListeningPolicy: Cache flushed: uuid-key-mapping 2020-08-11 18:42:59,778 TRACE ule.advancedcache.SiteAwareFlushAllListeningPolicy: Cache flushed: defaultPageCache 2020-08-11 18:43:30,407 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@54cf2a64[gzippedContent=5459 bytes,plainContent=24683 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597163944277,originalUrl=http://localhost:8080/dx-core-webapp/travel.html,timeToLiveInSeconds=-1]} 2020-08-11 18:43:30,407 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@54cf2a64[gzippedContent=5459 bytes,plainContent=24683 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597163944277,originalUrl=http://localhost:8080/dx-core-webapp/travel.html,timeToLiveInSeconds=-1] 2020-08-11 18:43:30,410 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel/main/0', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{mgnlCacheVariant={9b13970f-6b1b-451e-83fc-36cfde37f78e=0}}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@4cddec84[gzippedContent=914 bytes,plainContent=4033 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164098100,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/0,timeToLiveInSeconds=-1]} 2020-08-11 18:43:30,411 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@4cddec84[gzippedContent=914 bytes,plainContent=4033 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164098100,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/0,timeToLiveInSeconds=-1] 2020-08-11 18:43:30,413 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=travel, cacheKey=DefaultCacheKey{uri='/travel/main/00', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{mgnlCacheVariant={9b13970f-6b1b-451e-83fc-36cfde37f78e=0}}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@5ea1a6d6[gzippedContent=660 bytes,plainContent=2432 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164098132,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/00,timeToLiveInSeconds=-1]} 2020-08-11 18:43:30,414 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@5ea1a6d6[gzippedContent=660 bytes,plainContent=2432 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164098132,originalUrl=http://localhost:8080/dx-core-webapp/travel/main/00,timeToLiveInSeconds=-1] 2020-08-11 18:43:30,509 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=defaultPageCache, cacheKey=DefaultCacheKey{uri='/.imaging/mte/travel-demo-theme/1366/dam/tours/ruben-mishchuk-571314-unsplash/jcr:content/ruben-mishchuk-571314-unsplash.jpg', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=null} 2020-08-11 18:43:30,509 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=defaultPageCache, cacheKey=DefaultCacheKey{uri='/.imaging/mte/travel-demo-theme/1366/dam/tours/ash-edmonds-441220-unsplash/jcr:content/ash-edmonds-441220-unsplash.jpg', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=null} 2020-08-11 18:43:30,509 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=defaultPageCache, cacheKey=DefaultCacheKey{uri='/.imaging/mte/travel-demo-theme/1366/dam/tours/simon-mumenthaler-199501-unsplash/jcr:content/simon-mumenthaler-199501-unsplash.jpg', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=null} 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [browserTtlVoter] fired 2147483647 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [browserTtlVoter] fired 2147483647 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [serverTtlVoter] fired 2147483647 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [serverTtlVoter] fired 2147483647 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [browserTtlVoter] fired 2147483647 2020-08-11 18:43:30,512 DEBUG magnolia.module.cache.cachepolicy.voters.TtlVoting: voter [serverTtlVoter] fired 2147483647 2020-08-11 18:43:30,520 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@49a7691c[gzippedContent=115968 bytes,plainContent=121048 bytes,contentType=image/jpeg,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList={Last-Modified=[1597164210509], Content-Type=[image/jpeg]},lastModificationTime=1597164210509,originalUrl=http://localhost:8080/dx-core-webapp/.imaging/mte/travel-demo-theme/1366/dam/tours/simon-mumenthaler-199501-unsplash/jcr:content/simon-mumenthaler-199501-unsplash.jpg,timeToLiveInSeconds=-1] 2020-08-11 18:43:30,521 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@4dbda4b5[gzippedContent=170959 bytes,plainContent=171169 bytes,contentType=image/jpeg,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList={Last-Modified=[1597164210509], Content-Type=[image/jpeg]},lastModificationTime=1597164210509,originalUrl=http://localhost:8080/dx-core-webapp/.imaging/mte/travel-demo-theme/1366/dam/tours/ash-edmonds-441220-unsplash/jcr:content/ash-edmonds-441220-unsplash.jpg,timeToLiveInSeconds=-1] 2020-08-11 18:43:30,533 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@62ce6a95[gzippedContent=350291 bytes,plainContent=350324 bytes,contentType=image/jpeg,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList={Last-Modified=[1597164210509], Content-Type=[image/jpeg]},lastModificationTime=1597164210509,originalUrl=http://localhost:8080/dx-core-webapp/.imaging/mte/travel-demo-theme/1366/dam/tours/ruben-mishchuk-571314-unsplash/jcr:content/ruben-mishchuk-571314-unsplash.jpg,timeToLiveInSeconds=-1] 2020-08-11 18:43:52,271 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=useCache, cacheName=sportstation, cacheKey=DefaultCacheKey{uri='/sportstation.html', serverName='localhost', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=info.magnolia.module.cache.filter.InMemoryCachedEntry@7bc42522[gzippedContent=3921 bytes,plainContent=32293 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164079373,originalUrl=http://localhost:8080/dx-core-webapp/sportstation.html,timeToLiveInSeconds=-1]} 2020-08-11 18:43:52,271 DEBUG info.magnolia.module.cache.executor.UseCache : Serving info.magnolia.module.cache.filter.InMemoryCachedEntry@7bc42522[gzippedContent=3921 bytes,plainContent=32293 bytes,contentType=text/html,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1597164079373,originalUrl=http://localhost:8080/dx-core-webapp/sportstation.html,timeToLiveInSeconds=-1]
Expected:
The sportstation cache should be flushed.
Workaround:
Touch the cache config so the cache is restarted with all sites available.
Notes
If you look at the entire log site-aware-cache-problem.log you can see I have three sites. One other site called /home. This page seems to be cache with the defaultPageCache.
2020-08-11 18:39:47,213 DEBUG info.magnolia.module.cache.filter.CacheFilter : Cache policy result: CachePolicyResult{behaviour=store, cacheName=defaultPageCache, cacheKey=DefaultCacheKey{uri='/home.html', serverName='localhost', locale='en',
The home site does not have a site definition. However, shouldn't the cache be called "home" as well. It would be great if we could clarify in the instructions how it works.
When using the workaround of touching the cache config the log reports the caches as being uninitialized. See cache-uninitialized.txt
Solution
As hinted below in Viet's comment, site caches were not created correctly upon starting up Magnolia, since multisite module waits until all modules have started in order to register sites. In the same way, advanced cache initialises site aware caches upon ModulesStartedEvent after multisite is done registering sites.
- is caused by
-
MULTISITE-92 Multisite module: implement limitation
- Closed
- is depended upon by
-
MGNLADVCACHE-112 DOC: Clarify that site aware caching is tied to site definitions
- Closed
- is related to
-
MGNLADVCACHE-115 Unable to create site aware caches at startup
- Closed
-
MULTISITE-92 Multisite module: implement limitation
- Closed
-
MGNLADVCACHE-110 Improve advanced cache debug/trace logging
- Closed
-
MGNLCACHE-231 Improve cache debug/trace logging
- Closed
- mentioned in
-
Page Loading...
-
Page Loading...
-
Page Loading...
-
Page Loading...
-
Page Loading...
-
Page Loading...
-
Page Loading...
-
Page Loading...