[MGNLADVCACHE-118] Personalized variant will displayed for not personalized user Created: 22/Feb/17  Updated: 02/Mar/23

Status: Accepted
Project: Advanced Cache
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Bug Priority: Critical
Reporter: Frank Sommer Assignee: Robert Šiška
Resolution: Unresolved Votes: 0
Labels: maintenance, to-estimate, to-verify
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Component personalization


Attachments: PNG File cache-browser-error-case.png     PNG File cache-browser-working-case.png     PNG File first-request-with-cookie.png     Text File magnolia-debug.log     PNG File next-request-without-cookie-but same-response.png     JPEG File other-device-other-network-same-response.jpeg     PNG File screenshot-2.png     PNG File screenshot-3.png    
Issue Links:
Relates
relates to MGNLPN-354 Visitor trait not working properly Closed
Template:
Acceptance criteria:
Empty
Task DoD:
[ ]* Doc/release notes changes? Comment present?
[ ]* Downstream builds green?
[ ]* Solution information and context easily available?
[ ]* Tests
[ ]* FixVersion filled and not yet released
[ ]  Architecture Decision Record (ADR)
Bug DoR:
[ ]* Steps to reproduce, expected, and actual results filled
[ ]* Affected version filled
Date of First Response:
Epic Link: Support
Team: DeveloperX

 Description   

On demo instance (M5.5.2) I can reproduce this issue. Follow these steps:

  1. Opening https://demopublic.magnolia-cms.com/ in browser 1 (e.g. Firefox)
  2. Choose travel type 'cultural'
  3. Opening https://demoauthor.magnolia-cms.com/.magnolia/admincentral#app:jcr-browser:browser;/travel:treeview: and publish a node for cache flush on public instance
  4. Reload https://demopublic.magnolia-cms.com/ in browser 1
    1. cultured tours variant will be shown, because of your tourType cookie
  5. Opening https://demopublic.magnolia-cms.com/ in browser 2 (e.g. Chrome)
    1. cultured tours variant will be shown, BUG there is no tourType cookie
    2. with additional parameter the right original variant is displayed (e.g. https://demopublic.magnolia-cms.com/?test=1)

Another way to reproduce (from ahietala):

  1. Wait until the live demo resets. On the hour (:00) or half hour (:30).
  2. On the public instance, request the travel home page as a Chinese visitor.
     https://demopublic.magnolia-cms.com/travel?previewCountry=cn 
  3. Request the same page for an anonymous visitor.
    https://demopublic.magnolia-cms.com/travel
  4. Problem: Magnolia cached the personalized content variant (Temples of the Orient) and keeps serving it to a non-personalized visitor. Anonymous visitor should get the original content (Hut to Hut in the Swiss Alps).


 Comments   
Comment by Rainer Blumenthal [ 28/Feb/17 ]

Are there any news on this? Tomorrow I have to pressent the solution to the customer - and I'd like to give them a timeline for the fix.

Comment by Antti Hietala [ 28/Feb/17 ]

rainer, the issue is currently being worked on (In Progress). The fix will be in the next maintenance release, Magnolia 5.5.3. Release date is not set yet, expected in March.

Comment by Robert Šiška [ 02/Mar/17 ]

Hello.

We couldn't reproduce this issue with given steps on 5.5.3 nor 5.4.12 (with cp13n) and neither on current demo (5.5.2).
Could you please make sure that you have your browser cache disabled and try to reproduce again?

Best regards,
Robert

Comment by Frank Sommer [ 03/Mar/17 ]

I can still reproduce it. It doesn't depends on the browser cache.

Comment by Rainer Blumenthal [ 03/Mar/17 ]

Video of the bug:

https://www.dropbox.com/s/ie5mfbxfsbd2zv6/2017-03-03_1205.swf?dl=0

It is easy to reproduce ...

Comment by Roman Kovařík [ 13/Mar/17 ]

Hello rainer,
thanks for the detailed steps and the video. Unfortunately we are not able to reproduce it on Windows/Linux/OS, Firefox/Chrome/Safari, different people, trying to replicate every step from the video.
It looks like we need your help here.

This is how the caching of personalized pages should work (and works when we test it from our side):

  1. Empty cache.
  2. Request a personalized page.
  3. A personalized cache entry is saved into cache. you can check it in the cache browser https://demo.magnolia-cms.com/.magnolia/admincentral#app:cacheTools:browser;/:listview: . You get Requested cache entry is of type info.magnolia.advancedcache.personalization.cache.PersonalizedCacheEntry but only info.magnolia.module.cache.filter.InMemoryCachedEntry type is supported when you try to download this item.
  4. Request the personalized page for the second time.
  5. Cache sees the cached personalized cache entry thus calls the variant resolver to get the correct variant.
  6. InMemoryCachedEntry for the resolved variant is saved. You should be able to download it in the cache browser.
  7. You should be able to repeat the steps 3., 4. and get the correct variant.

It looks like you are somehow able to create an invalid cache entry.
Are you able to reproduce the error by any browser? Also your exact versions of browsers might help.
How do you refresh the page (CTRL+R, F5)?
How many times do you refresh the page in each step, is it always only once? (this can be important since the personalized caching works in multiple steps)

Thanks in advance.
Roman

Comment by Frank Sommer [ 14/Mar/17 ]

Hello Roman, hello Jan,
we can still reproduce it, just only with press F5. It doesn't depends on any OS or Browser version. With the cache browser I can see that in the error case only one cache entry will be created. In correct case 2 cache entries.

Requirements

  1. Browser 1 (e.g. Chrome) has the cookie
  2. Browser 2 (e.g. Firefox) has no cookie

Error case

  1. flush the cache by publish any website node in jcr browser
  2. press simple F5 in Browser 1
    1. personalized version will be shown
  3. press simple F5 in Browser 2
    1. personalized version will be shown
    2. cache browser shows only one entry

Working case

  1. flush the cache by publish any website node in jcr browser
  2. press simple F5 in Browser 2
    1. unpersonalized version will be shown
  3. press simple F5 in Browser 1
    1. personalized version will be shown
    2. cache browser shows two entries
Comment by Roman Kovařík [ 17/Mar/17 ]

Hi frank.sommer

For the error case, could you check that the created cache entry is incorrect? (use the download action, it's shouldn't be possible to download the personalized cache entry, if it's possible to download it, the cache entry is wrong).
As we already said, for all the people here (and we've tried also at home, from personal networks to omit an influence of our internal network), the two cache entries are created, no matter if the cookie is present in the first browser or not.
Could you profile the request and send complete request which is sent from the first browser (URL, cookies, headers...)?
Have you tried the same scenario from a different network or is it always the same network? Could some proxy cache the cookie or the page? Also an output of tracert or traceroute might help here.

Best regards
Roman

Comment by Frank Sommer [ 20/Mar/17 ]

Hi Roman, I attached screenshots from the requests for reproducing the error case.
See and

When I request the page from other network and other device, it is still the same errornous response.
See

Until 9:30 you would see the same response in your browser for https://demopublic.magnolia-cms.com/.

After that just call me and I will easily (just in two requests) set the demo instance in that state.

Comment by Roman Kovařík [ 23/Mar/17 ]

Hi frank.sommer,
we've deployed personalization caching with some debug logging to our demo. You can test yourself or ping me so I can set this up:

  1. Go to https://demopublic.magnolia-cms.com/.magnolia/admincentral#app:logTools:level;
  2. Set to DEBUG:
    info.magnolia.advancedcache.personalization.cache.PersonalizedCacheKeyGenerator
    info.magnolia.advancedcache.personalization.cache.PersonalizedCachePolicy
    info.magnolia.advancedcache.personalization.cache.PersonalizedCacheStore
  3. https://demoauthor.magnolia-cms.com/.magnolia/admincentral#app:cacheTools:browser
  4. Delete entries for demopublic.magnolia-cms.com:/
  5. Browser with the cookie: https://demopublic.magnolia-cms.com/
    2017-03-22 14:53:19,989 DEBUG cache.personalization.cache.PersonalizedCacheStore: Default: info.magnolia.module.cache.filter.InMemoryCachedEntry@10ad47a6[gzippedContent=5633 bytes,plainContent=26037 bytes,contentType=text/html;charset=UTF-8,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1490190799868,originalUrl=http://demopublic.magnolia-cms.com/,timeToLiveInSeconds=-1]
    2017-03-22 14:53:19,992 DEBUG cache.personalization.cache.PersonalizedCacheStore: Personalized: PersonalizedCacheEntry(http://demopublic.magnolia-cms.com/): website:/travel
    
  6. Browser without the cookie: https://demopublic.magnolia-cms.com/
    2017-03-22 14:55:26,595 DEBUG ache.personalization.cache.PersonalizedCachePolicy: Personalized item detected: CachePolicyResult{behaviour=useCache, cacheKey=DefaultCacheKey{uri='/', serverName='demopublic.magnolia-cms.com', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{}'}, cachedEntry=PersonalizedCacheEntry(http://demopublic.magnolia-cms.com:8080/): website:/travel}
    2017-03-22 14:55:26,598 DEBUG ersonalization.cache.PersonalizedCacheKeyGenerator: Variant names: {13c12166-b457-463d-90b4-411d07cc445f=01, 2bf3e57c-11b5-497e-806b-0e06dacffded=00, 9b13970f-6b1b-451e-83fc-36cfde37f78e=0}
    2017-03-22 14:55:26,598 DEBUG ache.personalization.cache.PersonalizedCachePolicy: Personalized: CachePolicyResult{behaviour=store, cacheKey=DefaultCacheKey{uri='/', serverName='demopublic.magnolia-cms.com', locale='en', channel='all', params={}', secure='false', method='get', additionalAttributes='{mgnlCacheVariant={13c12166-b457-463d-90b4-411d07cc445f=01, 2bf3e57c-11b5-497e-806b-0e06dacffded=00, 9b13970f-6b1b-451e-83fc-36cfde37f78e=0}}'}, cachedEntry=null}
    2017-03-22 14:55:26,682 DEBUG cache.personalization.cache.PersonalizedCacheStore: Default: info.magnolia.module.cache.filter.InMemoryCachedEntry@12f6aba6[gzippedContent=4675 bytes,plainContent=19095 bytes,contentType=text/html;charset=UTF-8,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1490190926598,originalUrl=http://demopublic.magnolia-cms.com:8080/,timeToLiveInSeconds=-1]
    
  7. You can download the DEBUG log here: https://demopublic.magnolia-cms.com/.magnolia/admincentral#app:logTools:list;
Comment by Frank Sommer [ 04/Apr/17 ]

I can still reproduce this issue and had the cache classes set to debug. But in error case only one message is logged in the magnolia-debug.log file.

DEBUG  info.magnolia.advancedcache.personalization.cache.PersonalizedCacheStore 04.04.2017 10:06:51 -- Default: info.magnolia.module.cache.filter.InMemoryCachedEntry@6c199a1d[gzippedContent=5768 bytes,plainContent=28808 bytes,contentType=text/html;charset=UTF-8,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1491293210758,originalUrl=https://demopublic.magnolia-cms.com/,timeToLiveInSeconds=-1]

On request with the second browser (no-cookie) no further log messages will be logged.

Comment by Roman Kovařík [ 05/Apr/17 ]

Hi frank.sommer,
We haven't added this this ticket into this week sprint since there was no answer till Monday and we are already pretty busy for this week, but we'll try to push the ticket into next week sprint .

rkovarik

Comment by Robert Šiška [ 13/Apr/17 ]

Hello frank.sommer

Could you please reproduce the issue once again, download the DEBUG log and send it to us?
We believe that debug messages should now be verbose enough to finally give us clue about the problem.

Thank you,
rsiska

Comment by Rainer Blumenthal [ 13/Apr/17 ]

frank is back on tuesday

Comment by Antti Hietala [ 28/Apr/17 ]

rainer / frank.sommer Do you have an update on this? Kindly try to reproduce.

Comment by Frank Sommer [ 12/May/17 ]

It's still easy to reproduce for us. In error case only one line is still logged.

DEBUG  info.magnolia.advancedcache.personalization.cache.PersonalizedCacheStore 12.05.2017 14:46:24 -- Default: info.magnolia.module.cache.filter.InMemoryCachedEntry@7036bd05[gzippedContent=5768 bytes,plainContent=28808 bytes,contentType=text/html;charset=UTF-8,characterEncoding=UTF-8,statusCode=200,serializableHeadersBackingList=<null>,lastModificationTime=1494593183891,originalUrl=https://demopublic.magnolia-cms.com/,timeToLiveInSeconds=-1]

In success case there are some more lines in the log file.

The whole log file is attached. See magnolia-debug.log

It is reproducable by https://demo-features.magnolia-cms.com/travel/, too.

Comment by Rainer Blumenthal [ 15/May/17 ]

Now the feature is about to be used in the LIVE system and I assume we will come back to you soon with very high pressure. This or the latest next week, it will cause a lot of trouble.

We posted 3 different ways to reproduce with really excellent screenshots and explanations, had two teamviewer sessions, and 2 times did the "log-file thing" meanwhile I really feel a little lost. On our side everybody can reproduce it, and the behaviour did not change since february. On Magnolia side nobody ever made it.

Did you ever try with a windows environment (Firefox / Chrome)?

Comment by Rainer Blumenthal [ 15/May/17 ]

We found out sth. interesting

If we first "clear the cache" and then do

  • the first request (already having a cookie) with a TOR Browser ... it is not reproducable
  • the first request (already having a cookie) with Chrome (from within Aperto network) ... it is reproducable

So there is sth. strange happening if the first request (after Cache flush) comes from within the Aperto network.

This lowers the pressure a little, but as long as the cause is not clear - it could also happen in other company networks. Worst case would be: If the Migros company network acts like that too

Comment by Karel de Witte [ 23/May/17 ]

Hi Rainer,

Could you try to exclude magnolia's domain from your intranet proxy's cache ?
I believe the session and p13n cookies are being cached by your intranet proxy.

Best regards,

Comment by Frank Sommer [ 23/May/17 ]

Sorry, I don't understand the relationship between a proxy cache and the wrong p13n cache state in Magnolia CMS. I mentioned before, that we could easily set the Magnolia CMS in this wrong state and after that everybody (Magnolia employees itself) see the wrong state in their browsers.

Generated at Sun Feb 11 23:11:12 CET 2024 using Jira 9.4.2#940002-sha1:46d1a51de284217efdcb32434eab47a99af2938b.