1630000 - Hitting Back sometimes shows old cached content

Status: RESOLVED FIXED

(Core :: Networking: Cache, defect, P2)

Description

[Randell Jesup [:jesup] (needinfo me)]

+++ This bug was initially created as a clone of Bug #1545909 +++
+++ This bug was initially created as a clone of Bug #1489624 +++

Still happening; same url for me as always (cnn.com), though people have reported it happening on other sites as well.

Browse to a url; wait long enough for the site to change content. Refresh to see current content (in CNN's case, it may auto-refresh periodically on it's own).

Browse to a sub-page on the site. Hit back. See original content; hitting refresh will load current content. You can now (usually/often) repeat the sequence; sometimes it will stop reproing after 1 or two instances.

I've also seen this across months and a restart - load a profile unused for a long time that was sitting on CNN before it was shut down (or perhaps had visited CNN "recently"). See current content (no refresh needed). Read an article, hit back, see months-old content. Refresh, see current, view article, back see months-old content.

I'll attach a screencast of this recorded against a local m-c build where it's happening repeatedly.

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

I went to record a debug log of this, and it had stopped reproing (I had to go to a meeting and eat lunch). I'll try to get one next time, though I doubt it will be different than the ones I provided in the past.

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

Attachment: cnn-2020-04-14_12.29.22.mkv

Comment 3

[Michal Novotny [:michal]]

Attachment: log.txt-main.17391.moz_log.xz

I've hit this bug several times this week on Fenix. I had problems to reproduce it when logging was turned on, but in the end I succeeded. The log confirms the theory with RCWN.

This channel creates the cache entry:
2020-04-23 10:47:27.740570 UTC - [Parent 17391: Main Thread]: D/nsHttp Creating nsHttpChannel [this=0x723d606000]

This channel loads newer version, but it isn't stored in the cache due to RCWN:
2020-04-23 15:42:37.406519 UTC - [Parent 17391: Main Thread]: D/nsHttp Creating nsHttpChannel [this=0x723d802000]

This channel loads the old version from the cache because VALIDATE_NEVER flag is used when navigating back in history:
2020-04-23 15:46:23.044312 UTC - [Parent 17391: Main Thread]: D/nsHttp Creating nsHttpChannel [this=0x7234d48000]

Comment 4

[Michal Novotny [:michal]]

There are couple of possible solutions for this:

1. When network wins we can doom the entry. This will ensure we won't reuse the entry, but we'll probably very often throw away an up-to-date entry.

2. When network wins we can always recreate the entry and store the new content. But the network won probably because the storage was busy and storing new content would just increase the load. IIRC, this was the reason why we decided to not cache the new content.

3. We could remember (probably in CacheIndex) that the entry wasn't used and might contain an old content. We wouldn't allow to use such entry without re-validation. For this we would need to ignore VALIDATE_NEVER flag.

Comment 5

[Kohei Yoshino [:kohei]]

I have seen this issue for a long time since 1 release before e10s was enabled (that’s Firefox 47?)

Comment 6

[Michal Novotny [:michal]]

(In reply to Kohei Yoshino [:kohei] from comment #5)

I have seen this issue for a long time since 1 release before e10s was enabled (that’s Firefox 47?)

In your case the cause is different because RCWN was enabled in mozilla59 on desktop and in mozilla62 on mobile.

Comment 7

[Michal Novotny [:michal]]

Attachment: Bug 1630000 - Hitting Back sometimes shows old cached content, r?mayhemer

If we're racing cache with network and the network wins we don't have a cache entry for writing the downloaded data. In this case nsHttpChannel::MaybeCreateCacheEntryWhenRCWN() creates the entry synchronously by calling nsICacheStorage::openTruncate() before we initialize cache entry for writing.

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/339020d52dcd
Hitting Back sometimes shows old cached content, r=mayhemer,necko-reviewers

Comment 9

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/339020d52dcd

Comment 10

[Timea Zsoldos [:zstimi/tzsoldos], Desktop QA]

Reproduced this issue with Fx nightly build from 2020.04.14 on windows 8.1 x64. Verified fixed with Firefox 78.0b9 on Windows 8.1 x64, macOS 10.15 and on Ubuntu 18.04.