158216 - Cookies are written out to disk too often

Status: VERIFIED FIXED

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

Description

[Robert John Churchill]

While doing some performance stats gathering regarding disk usage on
slow-I/O-write devices, it was noticed that cookies are written to disk too often.

The expectation would be only one write per top-level page load.  Instead,
"cookies.txt" can end up being written out multiple times.

To reproduce/debug:
o set Mozilla's disk cache to 0 (might care to empty both the memory and disk
caches as well)
o delete any existing "cookies.txt" from the profile you will be using
o set a breakpoint on  Cookie_Write()  in "nsCookies.cpp"
o browse to a site such as "http://www.cnn.com/" which often sets multiple cookies
o the Cookie_Write() breakpoint will fire multiple times

What's happening is that nsCookieService::OnStateChange() is a doc observer and
when the following happens:
      progressStateFlags & STATE_IS_DOCUMENT
and   progressStateFlags & STATE_STOP
it calls Cookie_Write().

The problem: the conditional test (above) is firing more than once for the given
document.

In the CNN case, you'll often see the state changing without an associated URL
as well as often when some top-level images load, as well as the final top-level
page load.  For example, on one run (ignoring the cases with no URLs):

http://ar.atwola.com/html/93103289/538355095/aol\?SNM=HIDF&width=234&height=60&target=_top&TZ=420&CT=I
http://ar.atwola.com/html/93114717/538355095/aol\?SNM=HIDF&width=120&height=60&target=_top&TZ=420&CT=I
http://www.cnn.com/

[Note: It is the URILoader() which is sending events to the doc observers.]

Since event notification has historically been less than 100% perfect, I'd
perhaps suggest a strategy where instead of writing out "cookies.txt"
immediately when an event match is made, instead coalesce the events into one
cookie write. 

Upon a notification which seems to indicate the load has finished, you could set
a timer to "fire-once" (if a timer isn't already outstanding or already firing)
in the near future (perhaps with a secord or so fire duration) which could then
call Cookie_Write()

Comment 1

[Kathleen :Brade]

I was doing a different performance analysis (for Chimera) and also noticed this
problem.  If possible, we'd like to see this addressed in the next month or so.

Comment 2

[Stephen P. Morse]

The best solution here is to never write out cookies while the browser is 
executing, and then write them all out when the browser is shut down.  The only 
justification for the frequent writing is in case the browser crashes, but our 
browser doesn't crash much anymore.  Right?

Attaching a patch that writes out the cookies only when the browser closes.

cc'ing pinkerton because this will undo part of the patch that he wanted for bug 
148213.

Comment 3

[Stephen P. Morse]

Attachment: write out cookies only when browser closes

Comment 4

[Mike Pinkerton (not reading bugmail)]

my $0.02 is that when told to clear cookies, they should be written out
immediately. i don't think that would affect page performance, right?

Comment 5

[Stephen P. Morse]

There some discussion in bug 148213 that suggests that we might want to save
cookies each time the user explicitly deletes some.  I'm not sure why that would
be important.  But if that's what we decide to do, then the change to the patch
would be as follows:

1. The removal of COOKIE_Write(PR_FALSE) following line 1930 in nscookies.cpp
would instead by a replacement of that line with simply COOKIE_write() -- that
is, keep the line but remove the parameter.  This is the code that is hit when
the user does cookie removals via the cookie-manager dialog

2. Same comment for the removal of ::Cookie_Write(PR_FALSE) in
nsCookieManager.cpp.  This is the code that is hit by Chimera's calls to
RemoveAll -- it is never used by the browser.

Comment 6

[Stephen P. Morse]

Pinkerton wrote in comment 4

> my $0.02 is that when told to clear cookies, they should be written out
> immediately. i don't think that would affect page performance, right?

That's correct -- there would be no affect on page performance if we wrote out
the cookies each time the user explicitly deleted some but not when new cookies
are added which occurs during page loading.

I have no strong feelings as to whether we go with my original patch (never
write out cookies until browser exits) or with my patch as modified by comment 5
(write them out when deleting but not when adding).  However I don't understand
the justification for the latter since we don't write out other things such as
prefs when they change but rather wait until browser exit to do so.

Comment 7

[Mike Pinkerton (not reading bugmail)]

yes, we do write out prefs when we close the pref window! try it.

Comment 8

[Mike Pinkerton (not reading bugmail)]

"This is the code that is hit by Chimera's calls to RemoveAll"

it's used by other embedded applications as well, not just chimera.

Comment 9

[Stephen P. Morse]

OK, based on Mike's comments, and the realization that we do write out prefs
when the prefs window changes, then I withdraw my original patch and recommend
going with the patch as modified in comment 5.

Comment 10

[Stephen P. Morse]

Attachment: write out cookies only when browser closes or user deletes cookies

Comment 11

[chris hofmann]

In quick launch mode would this patch write out cookies around time when a
session is ended under one profile, or would it wait for all sessions to end?

Comment 12

[Stephen P. Morse]

> In quick launch mode would this patch write out cookies around time when a
> session is ended under one profile, or would it wait for all sessions to end?

It would write it out when the browser is shut down.  In quicklaunch mode, the
browser shuts down and relaunches every time the last window is closed.

But I don't really understand the question.  What do multiple profiles have to
do with it?  Even under quicklaunch, you cannot be running with more than one
profile/session at a time.

Comment 13

[jag (Peter Annema)]

Comment on attachment 96868 [details] [diff] [review]
write out cookies only when browser closes or user deletes cookies

sr=jag

Comment 14

[Samir Gehani]

Comment on attachment 96868 [details] [diff] [review]
write out cookies only when browser closes or user deletes cookies

r=sgehani

Comment 15

[Stephen P. Morse]

patch checked in.

Comment 16

[Stephen P. Morse]

I just opened bug 166500 on the crash

In order to work on this current bug, I worked around the crash by using a very
simply test case of a page that sets a cookie.

Comment 17

[Stephen P. Morse]

Backed out the part of the patch that doesn't write the cookies after each page
finishes loading.  It caused a regression (see bug 165563).

Therefore reopening this bug

Comment 18

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

Since bug 165563 is closed. copying a comment:

May I suggest saving the cookies on imminent-shutdown instead of when the
service is terminated.  At that point the system is still up.  See my patch in
bug 149764.

Comment 19

[Stephen P. Morse]

Attachment: write out cookies when timer expires after page loads

Comment 20

[Samir Gehani]

Comment on attachment 98153 [details] [diff] [review]
write out cookies when timer expires after page loads

>+#define COOKIE_TIMEOUT 15000 // fire every 15 seconds

Are we firing the timer 15 seconds after somewhere in the middle of page load? 
Is that too long?

>+nsCOMPtr<nsITimer> mTimer;

Is this a member or a global?  Why is it a global?  If it is indeed a global
the prefix should be `g', rather than `m'.

> 
> nsCookieService::nsCookieService()
> {
>@@ -72,7 +76,12 @@
> 
> nsCookieService::~nsCookieService(void)
> {
>-  COOKIE_Write();
>+  if (mTimer) {
>+    // be sure to cancel the timer, as it holds a weak reference back to nsCookieService
>+    mTimer->Cancel();
>+    mTimer = nsnull;
>+  }
>+

OK, so we aren't writing out the cookies but we also appear to be cancelling
the timer: so when do the cookies that are queued to be written out upon last
page load but before last COOKIE_Write() get written?  Or am I missing
something?

>+
>+void
>+FireTimer(nsITimer* aTimer, void* aClosure) {
>+  if (mTimer) {
>+    // be sure to cancel the timer, as it holds a weak reference back to nsCookieService
>+    mTimer->Cancel();
>+    mTimer = nsnull;
>+  }

If we use a NS_TYPE_ONE_SHOT timer we won't need to cancel the timer here.

> NS_IMETHODIMP 
> nsCookieService::OnStateChange(nsIWebProgress* aWebProgress, 
>                                nsIRequest *aRequest, 
>                                PRUint32 progressStateFlags, 
>-                               nsresult aStatus)
>-{
>-    if (progressStateFlags & STATE_IS_DOCUMENT)
>-        if (progressStateFlags & STATE_STOP)
>-            COOKIE_Write(); // will remove this once bug 158216 is fixed
>-            COOKIE_Notify();
>+                               nsresult aStatus) {
>+  if ((progressStateFlags & STATE_IS_DOCUMENT) && (progressStateFlags & STATE_STOP)) {
>+
>+    COOKIE_Notify();
>+
>+    if (mTimer) {
>+      // be sure to cancel the timer, as it holds a weak reference back to nsCookieService
>+      mTimer->Cancel();
>+      mTimer = nsnull;

We do this in several places?  Don't we need to Release() the timer?  Simply
setting it to null will probably leave it in the TimerThread's timers array. 
Unless Cancel() does a Release() as well which would be odd.

>+    }
>+
>+    nsresult rv;
>+    mTimer = do_CreateInstance("@mozilla.org/timer;1", &rv);

Do we want to recreate a timer every time?  Why do we Cancel() the above one? 
Don't we in fact want to not Cancel() so that we are coalescing the writes as
rjc suggests?  Also, this brings me to the question of locking.  If a timer is
firing while a cookie is being set in the memory-resident table then will we
encounter race conditions such that cookies will be ``forgotten'' and won't be
added to the file.  This probably isn't a problem with the current
NS_TYPE_REPEATING_SLACK type timers which I go on to comment about below.  But
if we move to NS_TYPE_ONE_SHOT timers we may need to worry about this issue.

>+    if (NS_FAILED(rv) || (!mTimer)) return NS_ERROR_FAILURE;
>+    mTimer->Init(FireTimer, this, COOKIE_TIMEOUT, PR_TRUE, 
> NS_TYPE_REPEATING_SLACK);

Do you want to be using a NS_TYPE_ONE_SHOT timer?  Why do we need a repeating
timer here?

>+    // Note: don't addref "this" as we'll cancel the timer in the 
> nsBookmarkService destructor

You mean nsCookieService destructor?

>   if (!nsCRT::strcmp(aTopic, "profile-before-change")) {
>     // The profile is about to change.
>-    
>-    // Dump current cookies.  This will be done by calling 
>-    // COOKIE_RemoveAll which clears the memory-resident
>-    // cookie table.  The reason the cookie file does not
>-    // need to be updated is because the file was updated every time
>-    // the memory-resident table changed (i.e., whenever a new cookie
>-    // was accepted).  If this condition ever changes, the cookie
>-    // file would need to be updated here.
>-
>+    if (mTimer) {
>+      // be sure to cancel the timer, as it holds a weak reference back to nsCookieService
>+      mTimer->Cancel();
>+      mTimer = nsnull;
>+      COOKIE_Write();
>+    }
>     COOKIE_RemoveAll();
>     if (!nsCRT::strcmp(someData, NS_LITERAL_STRING("shutdown-cleanse").get()))
>       COOKIE_DeletePersistentUserData();
>@@ -226,9 +255,6 @@
>     // The profile has aleady changed.    
>     // Now just read them from the new profile location.
>     COOKIE_Read();
>-  } else if (!nsCRT::strcmp(aTopic, "session-logout")) {
>-    // Quicklaunch exit -- need to remove session cookies.
>-    COOKIE_RemoveSessionCookies();

Does the COOKIE_Write() just above do this?  Why are we removing this code?

Comment 21

[Stephen P. Morse]

Attachment: address the issues on comment 20

Comment 22

[Stephen P. Morse]

Attachment: Added locks to prevent cookie list from being modified while it is being written out

Comment 23

[Stephen P. Morse]

Attachment: Same as previous patch but this one really works. (Ignore nsCookies.cpp part)

Comment 24

[Johnny Stenback (:jst)]

Comment on attachment 98537 [details] [diff] [review]
Same as previous patch but this one really works.  (Ignore nsCookies.cpp part)

I don't see why the locking code is needed at all here. None of this code is
thread safe AFAICT, and from what I understand of this area of the code we're
guaranteed to always execute this code on the main thread. Even the timer
callback is quaranteed to come back on the same thread, so I don't see what the
locking does for us. And if we really do need this locking, then us
nsAutoMonitor to do the locking, see nsAutoLock.h for details on that.

Comment 25

[Stephen P. Morse]

Lock code was added because samir claimed that the timer callback could occur on
any thread.  But if that is not the case, then you are correct that the locking
code is not needed.  I'll remove it.

> OK, so we aren't writing out the cookies but we also appear to be cancelling
> the timer: so when do the cookies that are queued to be written out upon last
> page load but before last COOKIE_Write() get written?  Or am I missing
> something?

That is correct, the cookies that are accumulated in the last five seconds
(shortened from 15) prior to closing the browser will be lost.  But that's
better than losing all the cookies from the current session.  It would be nice
to write out the cookies in the cookie modules destructor, but I originally had
that and then discovered that it was too late -- too many other things had
already closed down and I couldn't obtain the profile directory.

Also there is no guarentee that cookies are never lost.  For example, if there
are too many cookies, the browser will automatically start throwing some out. 
So if it's free to do that, there should be no objection to losing the last five
seconds worth of cookies (that's certainly not a common occurence).

> >-  } else if (!nsCRT::strcmp(aTopic, "session-logout")) {
> >-    // Quicklaunch exit -- need to remove session cookies.
> >-    COOKIE_RemoveSessionCookies();
>
> Does the COOKIE_Write() just above do this?  Why are we removing this code?

This part of the patch is actually some cleanup for another bug.  It's related
to this area so I decided to do it now.  Turns out that session-logout is no
longer used -- it was for the old turbo model which is no more.  Once this patch
is checked in, I'll search for and close out that other bug as well.

Comment 26

[Stephen P. Morse]

Comment on attachment 98537 [details] [diff] [review]
Same as previous patch but this one really works.  (Ignore nsCookies.cpp part)

Ignore the nsCookies.cpp part of the patch.  That's the lock mechanism, and is
not needed if timer callbacks always occur on the main thread.

Comment 27

[Stephen P. Morse]

Attachment: same patch but updated to new timer interface that went in last weekend

Comment 28

[Johnny Stenback (:jst)]

Couldn't you write out the cookies from a shutdown observer notification? That
shouldn't bee too late, or if that won't work then there's gotta be some other
place where that could be done. Sure, it's not the end of the world if we loose
a cookie, but I think loosing cookies just because you close the browser really
quickly after visiting a site seems like a bad idea (admittedly not something
that a lot of people would run into, unless sites set cookies from their
onunload handler). It is IMO a lot worse for us to loose cookies just becase we
didn't find a convenient place to put the code that would fix this (arguably
edge) case, than it is for us to loose a cookie due to a documented scenario
that's shared between all known implementations (i.e. if you have too many
cookies, or whatever).

I wouldn't imagine this being hard to do, so I'd like to see it done unless you
can convince me to change my mind.

In nsCookieService::OnStateChange():

+    // create timer if it doesn't already exist
+    if (!mTimer) {
+      nsresult rv;
+      mTimer = do_CreateInstance("@mozilla.org/timer;1", &rv);
+      if (NS_FAILED(rv) || (!mTimer)) return NS_ERROR_FAILURE;
+    }
+
+    // restart timer
+    mTimer->InitWithFuncCallback(FireTimer, this, COOKIE_TIMEOUT,
nsITimer::TYPE_ONE_SHOT);

Don't you need to cancel the timer you didn't just create it? You don't know
that you didn't already initialize that timer and it didn't already fire do you?

Comment 29

[Stephen P. Morse]

> Couldn't you write out the cookies from a shutdown observer notification? That
> shouldn't bee too late
>
> I wouldn't imagine this being hard to do, so I'd like to see it done unless you
> can convince me to change my mind.

Been there, done that, and it was too late.  I had tried observing
xpcom-shutdown and doing the writing there, but I found I couldn't access the
profile directory.  That was the same problem that I ran into when I tried doing
it from the nsCookieService descructor.

It's really not that terrible to lose the last five seconds worth of cookies.

> Don't you need to cancel the timer you didn't just create it? You don't know
> that you didn't already initialize that timer and it didn't already fire do
> you?

If it did fire, that's a good thing.  It means that at some previous time some
pages finished loading and I did the cookie-write for them.  Now I am going to
reused that time to accomplish the cookie-writes for the current page that
finished loading.

Originally I was cancelling previous timers (fired or otherwise), and samir
convinced me that that was an inefficient thing to do.

Comment 30

[Stephen P. Morse]

See discussion going on in bug 149764.

Comment 31

[Samir Gehani]

> Ignore the nsCookies.cpp part of the patch.  That's the lock mechanism, and is
> not needed if timer callbacks always occur on the main thread.

Oops, inspecting the code closer the timer thread posts the timer event to the
target thread.  Sorry for the false alarm.

> Originally I was cancelling previous timers (fired or otherwise), and samir
> convinced me that that was an inefficient thing to do.

I think we need to know if the timer has fired before we try to reinitialize it.
 If the timer has not fired we should not reinitialize was the case I was making
and hand-in-hand with that if the timer has fired then we do need to
reinitialize.  I don't know that there is any way to do this given the current
nsITimer interface.  

The alternate route would be to just Cancel() and reinitialize everytime in
OnStateChange() but that appears to put an unnecessary delay after the last
cookie was stored by the webpage.  I guess we still get the benefits of
coalescing though.

Comment 32

[jag (Peter Annema)]

Copying this from bug 149764:

------- Additional Comment #4 From Doug T  2002-09-05 14:32 -------

>Well, when XPCOM shutdown occurs we start losing the ability to do things like
open new services, etc, which we may need in processing the shutdown request. 

Although it isn't the cleanest solution, what most components do today is cache
the services which they require at shutdown during startup 

<snip>

------- Additional Comment #10 From Mike Shaver  2002-09-18 09:11 -------

Forgive me if this has been covered (I didn't see so), but would it not be
possible, and even a performance win, to cache the result of
NS_GetSpecialDirectory in the cookie module?  Then you'd have everything you
need to write out the file, without requiring any additional service operations.

-----------------

This sounds like a better solution to me than this timer based one.

Comment 33

[Stephen P. Morse]

Attachment: cache NS_GetSpecialDirectory so we can write out cookie file at shutdown

Comment 34

[Stephen P. Morse]

I just attached a patch that caches the NS_GetSpecialDirectory so it can write
out the cookies at shutdown time.  This patch is independent of the time patch.
 So either or both of them can be taken.  If you take just the time patch, then
the last five seconds worth of cookies will be lost.  If you take just the
caching patch, then all collected cookies will be lost in the event of a crash.
 If you take both, then nothing is ever lost (the two patches together will
require some minor merging but it is obvious what needs to be done).

My recommendation is to take both patches.

Comment 35

[jag (Peter Annema)]

Comment on attachment 99901 [details] [diff] [review]
cache NS_GetSpecialDirectory so we can write out cookie file at shutdown

nsIFileSpec is deprecated. Could you store mDirSpec as a nsIFile to at least
not make it harder to get rid of nsIFileSpec?

For COOKIE_Write, don't use nsCOMPtr<> for the arguments, pass xdirSpec in as a
nsIFile* (and convert to nsIFileSpec inside COOKIE_Write, or better yet,
replace its nsIFileSpec use with nsIFile/nsILocalFile, though that should
perhaps be a new bug).

Comment 36

[Stephen P. Morse]

Attachment: addresses issues in comment 35

Comment 37

[Stephen P. Morse]

Attaching new patch which caches an nsIFile instead of an nsIFileSpec.

Also new patch installs a listener for xpcom-shutdown and writes out the cookies
at that time.  Previously I was attempting to do it in the nsCookieService
destructure.

Comment 38

[jag (Peter Annema)]

Comment on attachment 100893 [details] [diff] [review]
addresses issues in comment 35

sr=jag on your patch, but reading it I was reminded of something:

> {
>-    if (progressStateFlags & STATE_IS_DOCUMENT)
>-        if (progressStateFlags & STATE_STOP)
>-            COOKIE_Write(); // will remove this once bug 158216 is fixed
>-            COOKIE_Notify();
>+    if ((progressStateFlags & STATE_IS_DOCUMENT) && (progressStateFlags & STATE_STOP)) {
>+      COOKIE_Notify();
>+    }
>     return NS_OK;
> }
> 

I think that you could actually get away with calling COOKIE_Write() here if
you change this test to |(progressStateFlags & STATE_IS_NETWORK) &&
(progressStateFlags & STATE_STOP)|. If I understand things correctly,
|STATE_IS_DOCUMENT & STATE_START/STOP| is for each component on a page, e.g.
the html file but also all images, plugins, etc. in it, |STATE_IS_NETWORK &
STATE_START/STOP| is for the combined network start/stop events. A slightly
more complete check goes something like this:

if (NETWORK & START) {
  mInPage = PR_TRUE;
} else if (NETWORK & STOP) {
  mInPage = PR_FALSE;
  // end of document, write cookies
  COOKIE_Write(mDir);
  COOKIE_Notify();
} else if (DOCUMENT & STOP) {
  if (!mInPage) {
    // out of bounds load, write cookies
    COOKIE_Write(mDir);
    COOKIE_Notify();
  }
}

Those out of bounds loads happen for example when a page uses JS to load
additional images on user actions.

You don't have to incorporate this suggestion into the current patch, but I
think this is a nicer approach than the timer based patch since this will
reduce the COOKIE_Write() calls to when they could have changed.

Comment 39

[Samir Gehani]

Comment on attachment 100893 [details] [diff] [review]
addresses issues in comment 35

r=sgehani

Comment 40

[Stephen P. Morse]

Patch for writing out cookies on browser shutdown has been checked in.

The patch for writing out cookies based on a timer that fires after each page
finishes loading was not checked in.  And that was not part of the original bug
report.  Specifically, the bug description and comments 1-15 all deal with
writing out cookies after any deletions and on shutdown, but not on page loads.
 And the patch for that was checked in (comment 15) but then backed out (comment
17) because it wasn't actually writing out cookies on shutdown and therefore
caused a regression (bug 165563).  The current patch does correctly write out
cookies at shutdown, so the regression is no longer present.

Everything after comment 17 was a work-around for the fact that the shutdown
writing of cookies was not working.  That work-around is no longer needed since
the shutdown writing of cookies does work with the patch that was just checked in.

Therefore closing this bug as fixed because the original description and
comments 1 to 15 have all been taken care of.  If anyone feels now that cookies
are not being written out often enough (after each page loads), that should be
opened in a separate bug report.  That separate report can deal with the two
approaches mentioned in this report -- timer approach for which there is a
bit-rotted patch here
   http://bugzilla.mozilla.org/attachment.cgi?id=98913&action=view
as well as the network-stop approach that jag outlined in comment 38.

Comment 41

[Tom Everingham]

verified - confirmed with lxr patch checked in

Comment 42

[Asa Dotzler [:asa]]

not writing out often enough problem is now bug 165268

Comment 43

[timeless]

*** Bug 137512 has been marked as a duplicate of this bug. ***