Last Comment Bug 328598 - Places slow to shut down
: Places slow to shut down
Status: VERIFIED FIXED
swag: 5d
: fixed1.8.1
Product: Firefox
Classification: Client Software
Component: Bookmarks & History (show other bugs)
: Trunk
: All All
: P1 normal (vote)
: Firefox 2 alpha2
Assigned To: Brett Wilson
:
Mentors:
: 329793 330157 331244 (view as bug list)
Depends on:
Blocks: 330157 330332
  Show dependency treegraph
 
Reported: 2006-02-25 14:46 PST by Dave Townsend [:mossop]
Modified: 2009-11-26 06:07 PST (History)
18 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Patch to improve things a bit (2.13 KB, patch)
2006-03-10 10:04 PST, Brett Wilson
vladimir: superreview+
Details | Diff | Splinter Review
My timing code (1.72 KB, patch)
2006-03-10 10:05 PST, Brett Wilson
no flags Details | Diff | Splinter Review
Rewrite of history expiration (50.00 KB, patch)
2006-03-31 15:44 PST, Brett Wilson
bryner: review-
Details | Diff | Splinter Review
Patch addressing bryner's review (54.25 KB, patch)
2006-04-07 13:35 PDT, Brett Wilson
bryner: review+
Details | Diff | Splinter Review

Description Dave Townsend [:mossop] 2006-02-25 14:46:26 PST
With places switched on, firefox takes a good few seconds to shut down. If you attempt to start firefox while it is in the phase, does not open a new window, and leaves two firefox.exe processes in the task manager until either one is manually ended.

This is extremely irritating when restarting the browser after installing extensions etc.
Comment 1 Brett Wilson 2006-02-25 15:13:55 PST
I'm not sure what to do about this. There are two causes for slow shutdown. First, it has to flush any existing writes to disk. If you just added a bunch of pages or bookmarks, itmight take a few seconds to flush it (though this is not a huge problem in practice) and we delete expired history.

We might be able to further optimize the query we use for deleting history (if your history file was created with a places build before Feb 14, you won't have a date index which will make it much slower).

However, it will take some time to delete history and flush to disk (probably more than without places), and we can't really do anything about that. Any solution probably involves not expiring all necessary history when the browser shuts down. We could perhaps do smaller parts at a time, by limiting the query. We could also just do it every few runs, so it will only slow to shutdown some of the time.
Comment 2 Dave Townsend [:mossop] 2006-02-25 16:36:20 PST
Right now, if I shutdown firefox immediately after opening it it takes about 12 seconds to disappear from the task list. This is in comparison with about 1 second for firefox 1.5 with a similar set of bookmarks and history.

sqlite says I have the index moz_historyvisit_dateindex if that's what you're talking about.

I'm not necessarily saying that the shutdown time should be speeded up, I accept that it may not be possible (though anything over 5 seconds seems like its a bit too slow). I'm more interested in seeing firefox not become unusable (without ending a process or rebooting) because of it.
Comment 3 Ria Klaassen (not reading all bugmail) 2006-02-26 03:47:38 PST
Can't it be written to the database in realtime? I remember slow startups/shutdowns were always in the problems top 5 on WinXP forums. People do all kind of things to change that, while most people only start up and shutdown their system once a day. 
A slow shutdown of a browser would really be a pain because most users restart their browser multiple times. I'm afraid a message "Firefox is still updating the database..." will not be sufficient.
Comment 4 Brett Wilson 2006-02-26 07:32:17 PST
Asynchronous flushing to disk makes the difference between a nice snappy browser and a barely usable one. And, it doesn't really affect the absolute time required to write the data. Most of the time is waiting for disk syncs, time which is basically lost from the perspective of the browser.

Does you notice this problem mostly in the case where you shutdown right after you startup? Or arae thereother situations where shutdown in unacceptably slow? I believe there are a bunch of write operations associated with opening the database. There is a small chance we can reduce these.
Comment 5 Dave Townsend [:mossop] 2006-02-26 07:59:41 PST
Just tried using this browser for about a quarter of an hour and then closing. It still took about the same time to shutdown.

I didn't mention before, but while it is shutting down, firefox uses a lot of CPU time, normally around 95%.
Comment 6 Brett Wilson 2006-02-26 08:04:59 PST
OK, so the time you're seeing is probably expiring history or something else rather than flushing to disk. We'll have to profile this.
Comment 7 Ria Klaassen (not reading all bugmail) 2006-02-26 08:56:01 PST
When I only open and close a trunk build it takes 2,5 seconds before the parent.lock disappears. When I do the same with a places build it takes 4 to 4,5  seconds before the lock file and the journal file are gone. This causes a "Firefox is already running" message here when I try to restart immediately. 
Using a 24 Feb build. The bookmarks-history.sqlite file weighs 2,5 MB.
Comment 8 Ria Klaassen (not reading all bugmail) 2006-02-26 10:02:55 PST
Hm, when I do the same using a large, imported history file (bookmarks-history.sqlite of 12,8 MB) it takes 9 to 10 seconds to shutdown.
If wonder if that's because it's *large* or *imported*.
Comment 9 :Gavin Sharp [email: gavin@gavinsharp.com] 2006-03-08 09:33:04 PST
*** Bug 329793 has been marked as a duplicate of this bug. ***
Comment 10 Ryuichi KUBUKI 2006-03-08 15:58:51 PST
It took me 5-6 seconds. bookmarks_history.sqlite is 10MB.

Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9a1) Gecko/20060308 Firefox/1.6a1
Comment 11 Brett Wilson 2006-03-10 10:04:41 PST
Created attachment 214693 [details] [diff] [review]
Patch to improve things a bit

This patch disables the 0-filling of the database. For networked or slow disks, 0-filling the expired history entries on disk is the slowest part (on my networked drive it could take 30 seconds to delete 20000 history entries). This avoids that so the same task now takes about 6. For fast local disks, this might only save 2 seconds, but it will provide some relief for those using the nightlies and alpha.

This patch also re-enables vacuuming on history clearing because deleted items are no longer overwritten.

I'm interested in reported shutdown speeds on different systems when this patch goes in. If speed is still insufficient on many systems, we'll have to do something else. Expiring history as you browse ends up being pretty tricky so it would be best avoided.
Comment 12 Brett Wilson 2006-03-10 10:05:50 PST
Created attachment 214694 [details] [diff] [review]
My timing code

This patch is the code I was using to time the statements. I'm attaching it here because I'll lose it otherwise.
Comment 13 Brian Ryner (not reading) 2006-03-10 10:27:21 PST
Comment on attachment 214693 [details] [diff] [review]
Patch to improve things a bit

Hm, I'm not sure how comfortable I am with the sqlite3/Makefile.in change.  If we're providing mozstorage as a generic service, it seems like there would be consumers who _do_ want deletes to always be zeroed.  Is there a way we can make this a per-connection / per-table / whatever option?
Comment 14 Brett Wilson 2006-03-10 11:17:07 PST
Comment on attachment 214693 [details] [diff] [review]
Patch to improve things a bit

Vlad: can you approve this storage change? There is a good chance we'll change it back, but this patch will temporarily make shutdown times reasonable for testing.
Comment 15 Vladimir Vukicevic [:vlad] [:vladv] 2006-03-10 11:40:21 PST
Comment on attachment 214693 [details] [diff] [review]
Patch to improve things a bit

That looks fine to me -- if the user requests clear privacy data, we still clear from the disk, and that should be good enough (esp. for now).
Comment 16 Brett Wilson 2006-03-10 13:03:22 PST
First patch is on trunk and branch. Leaving open so we can see the impact.
Comment 17 Peter van der Woude [:Peter6] 2006-03-10 15:58:45 PST
this appears to have fixed bug 327818 and bug 327819
Comment 18 Radek 'sysKin' Czyz 2006-03-10 19:21:50 PST
I'm sorry for a useless comment but even zeroing entire 12MB file should not take more than tens of milliseconds on modern cached filesystem... Just what exactly is sqlite doing that requires such amazing CPU power?
Comment 19 Ria Klaassen (not reading all bugmail) 2006-03-11 01:29:38 PST
I retried the same history.dat file from comment #8 and sad to tell that it still takes exactly the same time to shut down.
Comment 20 Peter van der Woude [:Peter6] 2006-03-11 02:33:46 PST
(In reply to comment #19)
> I retried the same history.dat file from comment #8 and sad to tell that it
> still takes exactly the same time to shut down.
> 
I notice the same, but sometimes it takes<1sec and sometimes a lot more.
maybe it's something else causing the days aswell
Comment 21 Ria Klaassen (not reading all bugmail) 2006-03-11 02:51:20 PST
(In reply to comment #20)
>
I saw the same but I think now it could be due to the fact that history is 9 days by default in a new profile and in my default profile 300 days or such. 
When I start the large history file with a default setting of 9 days it will take a long time to shut down for the first time but the next times much shorter.
Comment 22 Brett Wilson 2006-03-11 20:43:44 PST
*** Bug 330157 has been marked as a duplicate of this bug. ***
Comment 23 Andreas Morawietz 2006-03-12 02:30:19 PST
I think, the slow shutdown isn't the main problem.

The real problem is, that you can't start a new firefox, if the old one is still in memory.

To prevent such problems in future, the code of firefox should be changed in that way, that it should always be possible to start a new firefox, if there's already one running.
Comment 24 Ria Klaassen (not reading all bugmail) 2006-03-12 03:07:59 PST
If restarting is the main problem, the Restart Firefox extension might help. It restarts always quicker than manually, because it knows exactly when to start up so you never get "Firefox is already running..." messages. I've never seen them when I tried the extension in any case.
Comment 25 Andreas Morawietz 2006-03-12 03:16:52 PST
(In reply to comment #24)
> If restarting is the main problem, the Restart Firefox extension might help. It
> restarts always quicker than manually, because it knows exactly when to start
> up so you never get "Firefox is already running..." messages. I've never seen
> them when I tried the extension in any case.
> 

I don't get this message. 
But the problem is, that the new firefox closes, as soon as the old firefox in memory is finished with shutting down places. 
It's better described here: https://bugzilla.mozilla.org/show_bug.cgi?id=330157
Comment 26 Ria Klaassen (not reading all bugmail) 2006-03-12 03:22:58 PST
(In reply to comment #25)
>
I tried it out a lot in branch and trunk (really tens of times a day) but I never saw that it stayed in memory without displaying the message. Do you get the same result with a new profile? 
Comment 27 Brett Wilson 2006-03-12 08:55:25 PST
(In reply to comment #23)
> To prevent such problems in future, the code of firefox should be changed in
> that way, that it should always be possible to start a new firefox, if there's
> already one running.

Given the current architechure of Firefox, this is unfortunately not feasable, although many people agree that this is something we should try for in the future.
Comment 28 Brett Wilson 2006-03-13 14:30:42 PST
*** Bug 314635 has been marked as a duplicate of this bug. ***
Comment 29 Doug Shelton 2006-03-17 10:55:26 PST
(In reply to comment #11)
> Created an attachment (id=214693) [edit]
Brian, what is the reason for setting -DTHREADSAFE=1 in this patch?  It appears this is the item that is breaking BeOS builds.  Is it required for proper functioning or was it enabled as a possible performance enhancement?  
Comment 30 Brett Wilson 2006-03-17 11:04:08 PST
I assume you meant me. I think you can take it out. We were hoping to make it threadsafe and I set it while I was chaning defines. You can remove it if you want. Be warned that it might go back in the future if we actually do make it threadsafe.
Comment 31 Doug Shelton 2006-03-18 13:07:02 PST
(In reply to comment #30)
> I assume you meant me. I think you can take it out. We were hoping to make it
> threadsafe and I set it while I was chaning defines. You can remove it if you
> want. Be warned that it might go back in the future if we actually do make it
> threadsafe.
> 
Brett, please excuse the brain-cramp that caused me to address you improperly.  The issue we're having is, THREADSAFE causes builds to fail under BeOS.  BeOS has its own native threading, I believe supported elsewhere in Mozilla, and does not support pthreads.  We're proposing a patch that disables THREADSAFE for BeOS builds in bug 330340.  Please keep this in mind when examining the use of threads in the future.

Comment 32 Wayne Woods 2006-03-22 16:36:41 PST
OS X too -> All/All.

If I clear history, it goes away (till it eventually fills up again, over maybe 4 days). And if I transplant a bad copy of bookmarks_history.sqlite (7M or so) into another profile I can induce the bug. Only affects nightlies from 20060302 onwards, which was when Places was switched on. 
Comment 33 Brett Wilson 2006-03-31 15:44:42 PST
Created attachment 216876 [details] [diff] [review]
Rewrite of history expiration

This is a complete rewrite of the history expiration code. This new code expires little bits of history (currently 6 items per page). It does this on a timer slightly (currently 3.5 seconds) after the page is loaded to not interfere with page load time. It does not do any subsequent expirations until another page is loaded so as to not interfere with media playing as a plug in in the browser.

On shutdown we do an extra pass to catch dangling references. However, since there should be very few of these, it should be faster.

Since the expiration happens while you are browsing, the data is written to disk slowly instead of at shutdown, so doing 0-fill in sqlite won't delay shutdown. This re-enables 0-fill. With 0-fill we don't have to compress the DB when you explicitly clear history, which makes it much faster.
Comment 34 Brian Ryner (not reading) 2006-04-06 12:29:54 PDT
Comment on attachment 216876 [details] [diff] [review]
Rewrite of history expiration

As an overall comment, it would be nice if the "what does this function do?" comments were in the .h files instead of the .cpp files.  The comments on the imlementation are fine in the .cpp files.

Specific comments below:

>--- browser/components/places/src/nsNavHistory.cpp	29 Mar 2006 17:46:58 -0000	1.90
>+++ browser/components/places/src/nsNavHistory.cpp	31 Mar 2006 23:38:17 -0000
>@@ -442,16 +443,25 @@ nsNavHistory::InitDB(PRBool *aDoImport)
>         "favicon INTEGER)"));
>     NS_ENSURE_SUCCESS(rv, rv);
> 
>     rv = mDBConn->ExecuteSimpleSQL(
>         NS_LITERAL_CSTRING("CREATE INDEX moz_history_urlindex ON moz_history (url)"));
>     NS_ENSURE_SUCCESS(rv, rv);
>   }
> 
>+  // FIXME: this should be moved inside the moz_history table creation block.
>+  // It is left outside and the return value is ignored because alpha 1 did not
>+  // have this index. When it is likely that all alpha users have run a more
>+  // recent build, we can move this to only happen on init so that startup time
>+  // is faster. This index is used for favicon expiration, see
>+  // nsNavHistoryExpire::ExpireItems

This seems kind of fragile.  When we remove it, will anyone's profile that has the table but not the index become useless or at least slow?  How long does it take to run this CREATE INDEX if there's already an index?  Can we check whether there's already an index?

>@@ -2378,30 +2300,27 @@ nsNavHistory::RemovePagesFromHost(const 
> // nsNavHistory::RemoveAllPages
> //
> //    This function is used to clear history.
> 
> NS_IMETHODIMP
> nsNavHistory::RemoveAllPages()
> {
>   // expire everything
>-  VacuumDB(0);
>+  mExpire.ClearHistory();
> 
>-  // compress DB (compression is slow, but since the user requested it, they
>-  // either want the disk space or to cover their tracks). The dummy statement
>-  // must be stopped because vacuuming will change everything and invalidate
>-  // the cache.
>+  // Compress DB. Currently commented out because compression is very slow.
>+  // Deleted data will be overwritten with 0s by sqlite. Note that we have to
>+  // stop the dummy statement before doing this.
>+  /*

#if 0 is generally better than commenting out a block of code because it doesn't care if there are aleady comments inside the block.

>@@ -3987,16 +3904,17 @@ nsNavHistory::RemoveDuplicateURIs()
>       NS_ENSURE_SUCCESS(rv, rv);
>       rv = visitDelete->Execute();
>       NS_ENSURE_SUCCESS(rv, rv);
>     }
>   }
>   return NS_OK;
> }
> 
>+

extra whitespace change, may as well take it out

>--- /dev/null	1 Jan 1970 00:00:00 -0000
>+++ browser/components/places/src/nsNavHistoryExpire.cpp	31 Mar 2006 23:38:17 -0000
>+struct nsNavHistoryExpireRecord {
>+  nsCString uri;
>+  PRTime visitDate;
>+  PRInt64 visitID;
>+  PRInt64 pageID;
>+  PRInt64 faviconID;
>+  PRBool hidden;
>+  PRBool bookmarked;
>+  PRBool erased; // set to true when the history entry is erased
>+};

What do you think about having a constructor for this?  I'm worried if we start adding fields that it would be easy to forget to initialize one of them.  It could just be a default constructor that zeroes everything, or one that takes all of the values, or maybe one that takes the mozIStorageStatement and initializes everything.

>+void
>+nsNavHistoryExpire::OnAddURI(PRTime aNow)
>+{
>+  mAddCount ++;
>+  mSequentialRuns = 0;
>+
>+  if (mTimer && mTimerSet) {

I think it would be possible to get rid of mTimerSet if you nulled out mTimer and recreated it whenever you restart the timer.  I don't think the performance hit would be noticable, and it might make it less likely that you'd end up in some weird inconsistent state.

>+nsresult
>+nsNavHistoryExpire::DoPartialExpiration()
>+{
>+  mSequentialRuns ++;
>+
>+  //PRTime beginTime = PR_Now();
>+  PRBool keepGoing;
>+  ExpireItems(EXPIRATION_COUNT_PER_RUN, &keepGoing);
>+  //PRTime endTime = PR_Now();
>+  //printf("visits expired in %lld us\n", endTime - beginTime);

Did you mean to leave in this commented-out stuff for debugging?

>+nsresult
>+nsNavHistoryExpire::FindVisits(PRTime aExpireThreshold, PRUint32 aNumToExpire,
>+                               mozIStorageConnection* aConnection,
>+                               nsTArray<nsNavHistoryExpireRecord>& aRecords)
>+{
>+  nsresult rv;
>+
>+  // get info for expiring visits, special case no threshold so there is no
>+  // SQL parameter
>+  nsCOMPtr<mozIStorageStatement> selectStatement;
>+  nsCString sql("SELECT "

nsCAutoString (AssignLiteral might be slightly more efficient than passing this to the constructor, since it knows the length, but probably not a big deal).


>+  for (PRUint32 i = 0; i < aRecords.Length(); i ++) {
>+    if (aRecords[i].bookmarked)
>+      continue; // don't delete bookmarked entries
>+    if (Substring(aRecords[i].uri, 0, 6).EqualsLiteral("place:"))
>+      continue; // don't delete "place" URIs

You can use StringBeginsWith(aRecords[i].uri, NS_LITERAL_CSTRING("place:")) and avoid having to write out the length of "place:".

>+nsresult
>+nsNavHistoryExpire::ExpireHistoryParanoid(mozIStorageConnection* aConnection)
>+{
>+  // delete history entries with no visits that are not bookmarked
>+  // also never delete any "place:" URIs (see function header comment)
>+  nsresult rv = aConnection->ExecuteSimpleSQL(NS_LITERAL_CSTRING(
>+      "DELETE FROM moz_history WHERE id IN (SELECT id FROM moz_history h "
>+      "LEFT OUTER JOIN moz_historyvisit v ON h.id = v.page_id "
>+      "LEFT OUTER JOIN moz_bookmarks b ON h.id = b.item_child "
>+      "WHERE v.visit_id IS NULL "
>+      "AND b.item_child IS NULL "
>+      "AND SUBSTR(url,0,6) <> 'place:')"));
>+  NS_ENSURE_SUCCESS(rv, rv);

I assume this doesn't fail if there's nothing to delete... if it does fail, you shouldn't check rv unless you know there should be something there.

Same comment for ExpireFaviconsParanoid.

>+// nsNavHistoryExpire::ExpireForDegenerateRuns

I'm not crazy about "Degenerate", to me that sounds like a run that never loaded any pages.  But I can't really think of a better name right now.

>+nsresult
>+nsNavHistoryExpire::StartTimer(PRUint32 aMilleseconds)
>+{
>+  if (! mTimer)
>+    mTimer = do_CreateInstance("@mozilla.org/timer;1");
>+  if (! mTimer) {
>+    NS_NOTREACHED("Error creating timer");
>+    return NS_ERROR_UNEXPECTED;
>+  }

You can use NS_ENSURE_STATE(mTimer) as kind of a shorthand for this check, up to you.

>+// nsNavHistoryExpire::GetExpirationTimeAgo
>+
>+PRTime
>+nsNavHistoryExpire::GetExpirationTimeAgo()
>+{
>+  PRInt64 expireDays = mHistory->mExpireDays;
>+
>+  // Prevent Int64 overflow for people that type in huge numbers.
>+  // This number is 2^63 / 24 / 60 / 60 / 1000000 (reversing the math below)
>+  const PRInt64 maxDays = 106751991;

If the compiler can handle it, it seems like you could write out this computation (make the variable |static| as well) and it will be computed at compile time.
Comment 35 Brett Wilson 2006-04-06 12:57:31 PDT
> This seems kind of fragile.  When we remove it, will anyone's profile that has
> the table but not the index become useless or at least slow?  How long does it
> take to run this CREATE INDEX if there's already an index?  Can we check
> whether there's already an index?

We would remove it when we remove the alpha 1 migration code for some future milestone. I don't think we're concerned about letting people migrate from 2.0a1 to any previous version. When we remove the migration code, the annotation service won't work, so there's no point.


> I assume this doesn't fail if there's nothing to delete... if it does fail, you
> shouldn't check rv unless you know there should be something there.

Deletes succeed silently if there is nothing.

> If the compiler can handle it, it seems like you could write out this
> computation (make the variable |static| as well) and it will be computed at
> compile time.

Well, the compiler can't handle 2^63. I could hardcode 2^63 and do the rest at compile time.
Comment 36 Brett Wilson 2006-04-06 13:06:03 PDT
> I don't think we're concerned about letting people migrate from
> 2.0a1 to any previous version.

I meant any *later* version.
Comment 37 Brett Wilson 2006-04-07 13:35:52 PDT
Created attachment 217602 [details] [diff] [review]
Patch addressing bryner's review

This addresses most of your comments. I didn't change the nsCString to an nsCAutoString because the contents are much larger than AutoString's buffer and we would just waste 64 bytes of stack space. I also didn't expand the maxDays computation becuase the compiler won't expand 2^63. Writing 9223372036854775808 / 24 / 60 / 60 / 1000000 would be even dumber than what I have now.

This also includes the IDL I forgot in the last page that incluse onPageExpired and some changes on the favicon service's comments about expiration.
Comment 38 Dave Townsend [:mossop] 2006-04-08 10:45:44 PDT
After applying this patch I see an immediate improvement in shutdown speed. Went from nearly 5 seconds down to less that 1.

I did have to make some changes to get this to compile though. Changed the reference to nsNavHistoryExpireRecord in nsNavHistoryExpire.h to say it's a struct to match what is in nsNavHistoryExpire.cpp, and changed the parameter to the constructor of nsNavHistoryExpireRecord to be called selectStatement, matching what is in the code.
Comment 39 Jo Hermans 2006-04-09 17:00:35 PDT
*** Bug 331244 has been marked as a duplicate of this bug. ***
Comment 40 Brett Wilson 2006-04-10 16:05:28 PDT
On 1.8 branch and trunk.
Comment 41 Tracy Walker [:tracy] 2008-01-08 09:38:44 PST
Verified with nightly builds from 01-07-08
Comment 42 Gervase Markham [:gerv] 2009-11-26 06:07:36 PST
Bug 451915 - move Firefox/Places bugs to Firefox/Bookmarks and History. Remove all bugspam from this move by filtering for the string "places-to-b-and-h".

In Thunderbird 3.0b, you do that as follows:
Tools | Message Filters
Make sure the correct account is selected. Click "New"
Conditions: Body   contains   places-to-b-and-h
Change the action to "Delete Message".
Select "Manually Run" from the dropdown at the top.
Click OK.

Select the filter in the list, make sure "Inbox" is selected at the bottom, and click "Run Now". This should delete all the bugspam. You can then delete the filter.

Gerv

Note You need to log in before you can comment on or make changes to this bug.