1000338 - nsICacheEntry.lastModified not properly implemented

Status: VERIFIED FIXED

(Core :: Networking: Cache, defect)

Description

[Honza Bambas (:mayhemer)]

This is an internal property, not the value of Last-Modified http header.  

We never set the value.  Looking into the old cache code, apparently this is updated only internally when data or metadata are touched (nsCacheEntry::TouchData(), nsCacheEntry::TouchMetaData()).  

In the new cache there is however an exposed public method CacheFile::SetLastModified.  But it's never called by anyone.

I personally tend to let this be an internal property of CacheFile that is updated automatically to PR_Now() in CacheFile directly.

Comment 1

[Honza Bambas (:mayhemer)]

I think we can live with this for the first deployment.  This will only influence VALIDATE_ONCE_PER_SESSION loads (will be always re-validated) and some authenticated requests to be re-validated more often.

See fromPreviousSession usage in nsHttpChannel::OnCacheEntryCheck.  With this bug it's always at |true|.

Comment 2

[Honza Bambas (:mayhemer)]

lastFetched is affected as well, but there is no serious consumer for it except about:cache.

Comment 3

[Honza Bambas (:mayhemer)]

Attachment: v1

- removed SetLM from CacheFile/CacheFileMetadata
- LF, FC no longer controlled by CacheFileMetadata
- added OnFetched() to CacheFile/CacheFileMetadata that updates: FC++, LF=Now()
- MarkDirty() now does LM=Now() in selected cases
- CacheEntry calls CacheFile->OnFetched() when it gives itself to the consumer (callback)

This way it conforms the cache1 implementation, makes actually sense and also should be in sync with the IDL comments now.

Comment 4

[Honza Bambas (:mayhemer)]

Michal, ping on review here.  This is causing serious trouble.  Thanks.

Comment 5

[Michal Novotny [:michal]]

Comment on attachment 8482928 [details] [diff] [review]
v1

Review of attachment 8482928 [details] [diff] [review]:
-----------------------------------------------------------------

::: netwerk/cache2/CacheFileMetadata.cpp
@@ -720,5 @@
>      mBufSize = 0;
>    }
>    mOffset = 0;
>    mMetaHdr.mVersion = kCacheEntryVersion;
> -  mMetaHdr.mFetchCount = 1;

We must set something here since the value is in unknown state. So we should assign here 0.

::: netwerk/test/unit/test_cache2-28-last-access-attrs.js
@@ +4,5 @@
> +  function NowSeconds() {
> +    return parseInt((new Date()).getTime() / 1000);
> +  }
> +  function do_check_time(a, b) {
> +    do_check_true(Math.abs(a - b) < 0.5);

I think this can be unreliable. Couldn't we take one timestamp before calling asyncOpenCacheEntry() the second in OpenCallback() and check that the entry's timestamp falls  within this range?

Comment 6

[Honza Bambas (:mayhemer)]

https://tbpl.mozilla.org/?tree=Try&rev=06c33a700f17

Comment 7

[Honza Bambas (:mayhemer)]

Attachment: v1.1

Comment 8

[Honza Bambas (:mayhemer)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ce8f00cca9dd

Comment 9

[Carsten Book [:Tomcat]]

sorry also backedout for xpcshell-2 test failures like https://tbpl.mozilla.org/php/getParsedLog.php?id=47873428&tree=Mozilla-Inbound

Comment 11

[[e-mail]]

Dear Honza Bambas,

thank you for your reply explaining me that the bug 1064040 is related to this one. As you already know, the problem of the BACK button not working occurs in all sites with basic authentication, from Firefox ver. 32.0 on, and I guess this should be a major issue. I notice that bug 1000338 was first open in April 2014 and is still not patched, I hope it won't take so much time to solve this issue.

Also, please tell me if you still need the debug site I prepared at address http://95.110.161.29:42002/ or if I can close it.

Thank you very much,

Alessandro

Comment 12

[Honza Bambas (:mayhemer)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/6d54ee2b5a82

Comment 13

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/6d54ee2b5a82

Comment 14

[Honza Bambas (:mayhemer)]

Comment on attachment 8487801 [details] [diff] [review]
v1.1

Approval Request Comment
[Feature/regressing bug #]: cache2enable
[User impact if declined]: ill behavior when using back/forth navigation (unexpected document load errors) and probably more ; the significance of this metadata has been underestimated!
[Describe test coverage new/current, TBPL]: none (test needs to be be tuned up - it's time check based, i.e. not 100% reliable)
[Risks and why]: small, only risk would be some mistake in the code leading to e.g. a crash or something, but that would already be discovered, since this code is exercised by the whole platform and a tun of other tests
[String/UUID change made/needed]: none

Comment 15

[Sylvestre Ledru [:Sylvestre]]

Honza, could you provide a way to reproduce this issue for QA? Thanks

Comment 16

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/e69b76df294c
https://hg.mozilla.org/releases/mozilla-beta/rev/b88069789828

Do we need to track this for B2G v2.0 (b2g32)?

Comment 17

[Honza Bambas (:mayhemer)]

(In reply to Sylvestre Ledru [:sylvestre] from comment #15)
> Honza, could you provide a way to reproduce this issue for QA? Thanks

Let them use bug 1064040.  There is a very good test case!

Comment 18

[Honza Bambas (:mayhemer)]

(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #16)
> https://hg.mozilla.org/releases/mozilla-aurora/rev/e69b76df294c
> https://hg.mozilla.org/releases/mozilla-beta/rev/b88069789828
> 
> Do we need to track this for B2G v2.0 (b2g32)?

I think it's worth too.

Comment 19

[Honza Bambas (:mayhemer)]

Comment on attachment 8487801 [details] [diff] [review]
v1.1

Comment 14

Comment 20

[Teodora Vermesan (:TeoVermesan)]

Reproduced the issue on Firefox 32.0.2 build, verified as fixed on latest Aurora (build id:20140919030202), latest Nightly (build id: 20140919030202) and Firefox 33 Beta 5 (build id: 20140918174809) under: Windows 7 64bit, Mac OS X 10.9 and Ubuntu 64bit.

Comment 21

[[e-mail]]

Very nice job, Honza Bambas. The debug / fixing / testing process was fast. Now we just wait for the official release of Firefox 33. Thank you to all the team.
Alessandro Pasta

Comment 23

[bhavana bajaj [:bajaj]]

Honza,

for v2.0(based on gecko 32) we are only uplifting release show-stopper bugs. Can you give us your input on user impact/risk for FxOS to evaluate  how critical this is at this point the cycle given we are very close to ship. Else this may have to fixed in 2.1

had the Same question for 1066726..

Comment 24

[Honza Bambas (:mayhemer)]

(In reply to bhavana bajaj [:bajaj] from comment #23)
> Honza,
> 
> for v2.0(based on gecko 32) we are only uplifting release show-stopper bugs.
> Can you give us your input on user impact/risk for FxOS to evaluate  how
> critical this is at this point the cycle given we are very close to ship.
> Else this may have to fixed in 2.1
> 
> had the Same question for 1066726..

See bug 1063431 and then duplicates of bug 1066726.  Those are major regressions you may get in to.  This is worth uplifting.

Comment 25

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-b2g32_v2_0/rev/70b13579ddc1

Comment 26

[Kai-Zhen Li [:seinlin][:kli]]

http://hg.mozilla.org/releases/mozilla-b2g32_v2_0m/rev/70b13579ddc1

Comment 28

[François R-Champ]

This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU euballot - 1.1). With this version (which is the latest released version), running on Windows 7 64 bits, I still get some invalid entries in the cache (about:cache?storage=disk&context=), which shows as:
Data size = "0 bytes"
Last Modifed = "No last modified time (bug 1000338)"
Expires = "No expiration time"

I have the problem even after I empty the cache and far before the cache reaches its size limit.
So this bug should not be written as "fixed" or "verified" for v33. It's still not fixed.

Comment 29

[Honza Bambas (:mayhemer)]

(In reply to François R-Champ from comment #28)
> This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU

Do you have any problems with page loads or something unexpected that could be related to this bug?  If not I consider this bug as fixed.  What you see *may* be a bug, and if so, definitely a different bug than this one.  Please file it if you believe it's worth an attention and don't comment on closed bugs.  Thanks.

Comment 30

[kxmpex]

(In reply to Honza Bambas (:mayhemer) from comment #29)
> (In reply to François R-Champ from comment #28)
> > This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU
> 
> Do you have any problems with page loads or something unexpected that could
> be related to this bug?  If not I consider this bug as fixed.  What you see
> *may* be a bug, and if so, definitely a different bug than this one.  Please
> file it if you believe it's worth an attention and don't comment on closed
> bugs.  Thanks.

33.1.1 still have that bug.
Using alessandro.pasta's test link http://95.110.161.29:42002/, user=test, pwd=bug
"Expired document" appeared.
http://i.imgur.com/mwlM988.png
And the "0 bytes" in about:cache?storage=disk&context=
http://i.imgur.com/pbwI2Q5.png

My system is win7 x64.

Comment 31

[kxmpex]

(In reply to kxmpex from comment #30)

To reproduce it must have big disk cache entries.
I reproduced it when my disk cache entries is about 13210.

Comment 32

[Honza Bambas (:mayhemer)]

(In reply to kxmpex from comment #30)
> (In reply to Honza Bambas (:mayhemer) from comment #29)
> > (In reply to François R-Champ from comment #28)
> > > This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU
> > 
> > Do you have any problems with page loads or something unexpected that could
> > be related to this bug?  If not I consider this bug as fixed.  What you see
> > *may* be a bug, and if so, definitely a different bug than this one.  Please
> > file it if you believe it's worth an attention and don't comment on closed
> > bugs.  Thanks.
> 
> 33.1.1 still have that bug.
> Using alessandro.pasta's test link http://95.110.161.29:42002/, user=test,
> pwd=bug
> "Expired document" appeared.
> http://i.imgur.com/mwlM988.png
> And the "0 bytes" in about:cache?storage=disk&context=
> http://i.imgur.com/pbwI2Q5.png
> 
> My system is win7 x64.

Rechecked test case from bug 1064040 comment 2 on:
- a debug nightly build.  Works for me.  
- 33.1.1.  Works for me.
- 33.1.1 with a lowered cache limit and cache full, works for me.
- 32.X.  Broken, easy to reproduce.

I checked the actual fix is on 33.1.1 (current release sources).  

It has also been checked by our QA this is fixed on 33.

I think you are experiencing bug 1060082.

Comment 33

[kxmpex]

(In reply to Honza Bambas (:mayhemer) from comment #32)

Year,and it's interesting. It seems only happened to fat32 filesystem.

Comment 34

[kxmpex]

(In reply to kxmpex from comment #33)
Fat32 have max files in a folder limit.
And differend seems have different limit.....
Max files in a folder with 4k cluster have a limit is about 13xxx!!
I think that why i have that weird experience.

Comment 35

[François R-Champ]

(In reply to Honza Bambas (:mayhemer) from comment #29)
> (In reply to François R-Champ from comment #28)
> > This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU
> 
> Do you have any problems with page loads or something unexpected that could
> be related to this bug?  If not I consider this bug as fixed.  What you see
> *may* be a bug, and if so, definitely a different bug than this one.  Please
> file it if you believe it's worth an attention and don't comment on closed
> bugs.  Thanks.

Yes, the problem I am having is that some pages in cache do not load and of course it is a bug. When I look at the cache (about:cache?storage=disk&context=), all the cache entries of the pages which do not load have the following values :
 « Data size = "0 bytes"
Last Modifed = "No last modified time (bug 1000338)"
Expires = "No expiration time" »

As you can see Firefox itself is saying that this is bug number 1000338!

Comment 36

[Honza Bambas (:mayhemer)]

(In reply to François R-Champ from comment #35)
> (In reply to Honza Bambas (:mayhemer) from comment #29)
> > (In reply to François R-Champ from comment #28)
> > > This bug does not seem to be fixed in Firefox 33.1.1 (Mozilla Firefox EU
> > 
> > Do you have any problems with page loads or something unexpected that could
> > be related to this bug?  If not I consider this bug as fixed.  What you see
> > *may* be a bug, and if so, definitely a different bug than this one.  Please
> > file it if you believe it's worth an attention and don't comment on closed
> > bugs.  Thanks.
> 
> Yes, the problem I am having is that some pages in cache do not load and of
> course it is a bug. When I look at the cache
> (about:cache?storage=disk&context=), all the cache entries of the pages
> which do not load have the following values :
>  « Data size = "0 bytes"
> Last Modifed = "No last modified time (bug 1000338)"
> Expires = "No expiration time" »
> 
> As you can see Firefox itself is saying that this is bug number 1000338!


François, thanks for your comment.  Finally I understand what's going on here.

Sorry for later answer, I was indisposed for a time.


Apparently, it sometimes may happen we store an empty cache entry that we then use for rendering a page somehow.  Definitely a bug and definitely in or around the new cache2.


Connection to bug 1000338 is just coincidental.  The message in about:cache had to be removed with this bug (filed a new bug 1119394 on that).  What you see is a different, new bug (reported as bug 1119406).