Closed Bug 415201 Opened 17 years ago Closed 17 years ago

Firefox shutdowns very slow and with 100% CPU

Categories

(Firefox :: Bookmarks & History, defect)

defect
Not set
major

Tracking

()

VERIFIED FIXED
Firefox 3 beta4

People

(Reporter: ehume, Assigned: dietrich)

References

Details

Attachments

(2 files, 3 obsolete files)

User-Agent: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9b3pre) Gecko/2008013104 Minefield/3.0b3pre Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9b3pre) Gecko/2008013104 Minefield/3.0b3pre When I restart Minefield, other apps on my system bog down until it is done. Ditto when I am simply closing the beast. When fx3 is closing, the bogging down continues as long as Firefox.exe remains on the Task manager. This usually lasts more than half a minute on my system. Reproducible: Always Steps to Reproduce: 1. Close Firefox. 2. Do something with another app, like ExamDiff Pro or Outlook. Actual Results: All actions in other apps are slowed down until Firefox.exe leaves the Task manager. Expected Results: It should not interfere with other apps. My system: Dell Dimension running Win XP SP2 on 2.4GHz P4 with 1.25GB RAM, 200GB in two HD's.
Do you mean that Firefox closes slow and with high CPU usage ? Do you get the same in the Firefox safemode (http://kb.mozillazine.org/Safe_mode)?
I am getting 100% CPU usage for about 25 seconds, both in normal and safe mode. Thanks for suggesting those tests.
Do you have many Bookmarks or a big History ?
Summary: Firefox Minefield closing bogs down other apps → Firefox shutdowns very slow and with 100% CPU
Version: unspecified → Trunk
When did this start to happen? Before bug 399108 ?
places.sqlite = 6.60MB bookmarks.postplaces.html = 1.97MB The fx2 bookmarks.html that I extract the fx3 bookmarks from = 1.90MB I can restart fx2 in a few seconds. So far, I see nothing in Places worth trading that performance hit. And pray tell, how would a user know to clear his/her History? I'll clear mine and look at the performance.
Cleared the history. Shutdown only took 22 seconds of 100% CPU. And places.sqlite still is 6.60MB.
This started happening before Bug 399108. This is basically the reason I filed Bug 399108. It just never occurred to me to file a bug on it: I figured it was part of a performance problem that would eventually get taken care of. I filed this bug because it appeared that no one was addressing the issue.
Can you try a new profile ? (Create an additional test Profile with the profilemanager : http://kb.mozillazine.org/Profile_Manager)
I have seen this behaviour during the past few months. If i start Firefox, wait some seconds and directly close the program, it takes approximatly 23s with 95% CPU until the process finally dissapears. With a new profile and only the import of bookmarks.postplaces.html (2.3 MiB) there is not much of a difference. Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b3pre) Gecko/2008020200 Minefield/3.0b3pre places.sqlite: 13.4 MiB moz_bookmarks: approx. 3300 moz_historyvisits: approx. 40000 moz_places: approx. 20000 Debian Etch, Athlon XP 2500+, 1 GiB Ram It would be good to know, if this is the expected behaviour for a database of this size and my hardware.
I deleted everything but the extensions folder. Restated fx3 but installed no theme. Extensions are Mr Tech Local Install and Inspector Widget. fx3 then closed at 50% peak usage, but that was only a short spike. I then imported my fx2 bookmarks file. That took 20 seconds. Closing fx3 then took 20 seconds at 100% CPU usage.
Gutted the profile again, sparing the extensions folder. With no extensions except DOMi, fx3 on closing peaked at 63% CPU, but the whole process was 4-5 sec from zero to 63% to zero usage. Restored fx2 bookmarks again. 21-22 sec 100% CPU usage. Closing took 22-23 sec 100% usage.
Gutted it again, this time taking out the extensions folder - bare profile. fx3 closed with a 5-sec process that peaked at 47% CPU usage. Restoring the fx2 bookmarks took 21 sec 100% CPU usage. Closing fx3 took the same. How does one count the number of bookmarks?
Thanks for the testing, moving to places and I'll confirm this because it contains all needed informations except the bookmarks file which can't be attached because of the privacy. Someone should look at this before FF3.0 final, 21s shutdown is not acceptable.
Severity: normal → major
Status: UNCONFIRMED → NEW
Component: General → Places
Ever confirmed: true
Flags: blocking-firefox3?
QA Contact: general → places
Similar situation on Mac OS X 10.4.11. Bare profile shuts down in a couple of seconds but after importing a big bookmarks file (from Firefox 2) shutdown stalls for tens of seconds with a large CPU usage.
Can someone who's confirmed this please try the following, and post the shutdown times? 1. backup your profile 2. delete all your bookmarks from within the UI (sidebar, library) 3. close the browser, and note the shutdown time 4. open the browser 5. close the browser, and note the shutdown time That'd help very much, thanks.
Deleted bookmarks and history from inside the UI. I didn't get a precise time, but the bookmarks felt like a 20-sec deletion or longer. Closing Firefox was a 10-sec process, with a double spike, 81% and 75%.
Thanks Ed. Was that the first or second shutdown? Note that in my steps in comment #16, there are 2 shutdown numbers. (The second shutdown is the cost of history expiration sans bookmarks export or the cost of any unwritten transactions from deleting your bookmarks)
(In reply to comment #16) > Can someone who's confirmed this please try the following, and post the > shutdown times? 0a. Create a new profile 0b. Import bookmark file (takes some time) 0c. Close Minefield 38 seconds > 1. backup your profile Not done. > 2. delete all your bookmarks from within the UI (sidebar, library) Takes some time. (Except on a try when the folders got deleted from the UI but the bookmarks were still accessible on the toolbar or when searching...) > 3. close the browser, and note the shutdown time 5 seconds. > 4. open the browser > 5. close the browser, and note the shutdown time 7 seconds. > That'd help very much, thanks. Cheers.
Second and third shutdowns: 10 sec, 93% cpu peaks. Weird. There seemed to be a delay in opening fx2 after shutting down fx3, even when fx3 has no bookmarks.
Mozilla/5.0 (Windows; U; Windows NT 5.0; en-US; rv:1.9b3pre) Gecko/2008020304 Minefield/3.0b3pre ID:2008020304 PII 350MHz w/768MB RAM places.sqlite = 3756KB bookmarks.postplaces.html = 2711KB 59 seconds for firefox.exe to close = 100% CPU repeatable with a variation of only 2 or 3 seconds with a fresh Profile with only the default bookmarks in it 02 seconds for firefox.exe to close
> 2. delete all your bookmarks from within the UI (sidebar, library) 24s (ff2: 2s) > 3. close the browser, and note the shutdown time 8s > 5. close the browser, and note the shutdown time 7s Please see my previous comment for hardware and number of bookmarks/ history entries
Cross-post (might be helpful): I just finished monitored and analyzing, using Microsoft (Sysinternals) Process Monitor, a shutdown of Fx 3.0b3pre and I believe the shutdown delay problem may lie with Fx creating and operating on a file called "C:\Documents and Settings\<insert>\Application Data\Mozilla\Firefox\Profiles\<insert>\bookmarks.postplaces-1.html". I have a 1.56 MB Places file, and it took a total of about 8 seconds to shutdown. Of those 8 seconds, about 5 seconds was spent doing something related to the above file. I have no clue what is occuring during that process. Maybe this is part of the Fx bookmark backup process? But even if it were, it shouldn't take so long since even a manually performed bookmarks export is very quick. System specs: 933 MHz PIII; 512 MB RAM; WinXP SP2
so it could be connected to the creation of the backup files, this should be checked on the new json implementation (Bug 384370) On a 20MB places.sqlite my closing times are about 1s, but my bookmarks.postplaces is about 300KB (instead of some MB as i see here in most reports), so i probably don't see this slowdown
It would be great if someone who experiences this, could make their profile (or part of it that causes the issue) available (only do this if you're comfortable with this!).
Attached file bookmarks file to import (deleted) —
Ok, Ed graciously gave me his bookmarks.html file to find out how/where the slowdown on shutdown was happening (and I certainly could see it with his bookmarks file). He had appr. 4000 bookmarks. This is a bookmarks.html file with 4000 (dummy) links in it and this is also causing the massive slowdown on shutdown. The slowdown happens when every link in the bookmarks.html file is unique and when it has a last_charset="ISO-8859-1" attribute. With these 2 conditions met, the slowdown takes at least 20s, while without it, the slowdown is < 1 sec.
Thanks Martijn, that's extremely helpful information.
most of the time is spent fetching and converting the annotation for last_charset.
changing moz_annos_attributesindex to: CREATE INDEX moz_annos_attributesindex ON moz_annos (place_id, anno_attribute_id) took html export of martijn's file from ~30 seconds to ~3 seconds w/ a debug build.
Attached patch fix v1 (obsolete) (deleted) — Splinter Review
drop and recreate index on shutdown.
Assignee: nobody → dietrich
Status: NEW → ASSIGNED
Attachment #301830 - Flags: review?(mak77)
Comment on attachment 301830 [details] [diff] [review] fix v1 >+ // Do a one-time re-creation of the moz_annos index (bug 415201) >+ // XXX REMOVE ME AFTER BETA3. You missed the boat...
Comment on attachment 301830 [details] [diff] [review] fix v1 nice solution, we should have changed that index during indexes review :( while looking at this i found a bug in an anno query (not related to this bug), will fill with a patch and a test asap. + "CREATE INDEX moz_annos_attributes_compoundindex ON moz_annos (place_id, anno_attribute_id)")); i'd prefer moz_annos_placeattributeindex to follow other indexes naming conventions + // XXX REMOVE ME AFTER BETA3. + NS_LITERAL_CSTRING("CREATE UNIQUE INDEX interesting, we can't have 2 equal attribute_id for the same place_id with different values. We could consider doing the same for moz_items_annos_attributesindex. What do you think, could we do that here in this patch (that index should also be renamed to moz_items_annos_itemattributeindex)? yeah, as Reed said (lol) -> REMOVE ME BEFORE FINAL this is a fine change for me, we are already doing the same in moz_items_annos, could improve other queries too however with Bug 409945 we will move charset PageAnnos to itemAnnos
Attachment #301830 - Flags: review?(mak77) → review+
Attached patch fix v2 - fixes marco's comments (obsolete) (deleted) — Splinter Review
Drivers: This change considerably improves query speed for URI annotations. It improves the performance of HTML export of large bookmark sets by 6958%, thereby alleviating the pain at shutdown that many users on the build forum are complaining of.
Attachment #301830 - Attachment is obsolete: true
Attachment #301924 - Flags: review?(mano)
Attachment #301924 - Flags: approval1.9?
Comment on attachment 301924 [details] [diff] [review] fix v2 - fixes marco's comments removing review request, new patch coming.
Attachment #301924 - Flags: review?(mano)
Attachment #301924 - Flags: approval1.9?
Attached patch fix v3 (obsolete) (deleted) — Splinter Review
- drop and re-add moz_items_annos index to include UNIQUE constraint - remove "IF EXISTS" from the DROP statements, since we already know that
Attachment #301924 - Attachment is obsolete: true
Attachment #301937 - Flags: review?(mak77)
Comment on attachment 301937 [details] [diff] [review] fix v3 except that at this point, s/BEFORE FINAL/AFTER FINAL/ :(
Comment on attachment 301937 [details] [diff] [review] fix v3 good. + rv = mDBConn->IndexExists(NS_LITERAL_CSTRING("moz_items_annos_attributesindex"), &oldIndexExists); + NS_ENSURE_SUCCESS(rv, rv); + if (oldIndexExists) { this second check is not necessary, if the first index exists we already know that we should replace also the second, so we could simply drop it without an inner check and scope so we check 1 index, if it's found we know that we have to replace both (if you want a second check to be really sure, put a IF EXISTS in the second drop, and you have that free apart from that, fine!
Attachment #301937 - Flags: review?(mak77) → review+
Flags: blocking-firefox3? → blocking-firefox3+
Attached patch for checkin (deleted) — Splinter Review
Attachment #301937 - Attachment is obsolete: true
Comment on attachment 302186 [details] [diff] [review] for checkin er, prior to check-in i need to get review from a toolkit or places peer :)
Attachment #302186 - Flags: review?(mano)
Whiteboard: [has patch][needs review mano]
Blocks: 409945
OS: Windows XP → All
Hardware: PC → All
Comment on attachment 302186 [details] [diff] [review] for checkin r=mano
Attachment #302186 - Flags: review?(mano) → review+
Whiteboard: [has patch][needs review mano] → [has patch][has review]
Checking in toolkit/components/places/src/nsAnnotationService.cpp; /cvsroot/mozilla/toolkit/components/places/src/nsAnnotationService.cpp,v <-- nsAnnotationService.cpp new revision: 1.37; previous revision: 1.36 done Checking in toolkit/components/places/src/nsNavHistory.cpp; /cvsroot/mozilla/toolkit/components/places/src/nsNavHistory.cpp,v <-- nsNavHistory.cpp new revision: 1.249; previous revision: 1.248 done
Status: ASSIGNED → RESOLVED
Closed: 17 years ago
Resolution: --- → FIXED
Whiteboard: [has patch][has review]
Target Milestone: --- → Firefox 3 beta4
Whoof! My congratulations to all. On restart, the 100% CPU usage was 4 seconds. I must say that it was a shock for me to go from the 2008-02-13 to the 2008-02-16 build. Bravo. Just for reference, it still takes 22 seconds of 100% CPU usage to import the Bookmarks.html file, so the task for fx3 has not diminished. I am impressed. WFM.
Ed, what do you mean? Do you still get for 4 seconds 100% CPU usage on shutdown with the latest trunk build every time? That still seems too slow for me. Also 22 seconds for importing the bookmarks using 100% cpu seems like a bug to me. I guess this is bug 392193. You might want to throw your results in that bug. For me, the performance with shutdown after importing the " bookmarks file to import" file has improved so much that I can safely mark this verified. (also importing time seems smaller) Thanks for fixing this, Dietrich.
Status: RESOLVED → VERIFIED
To clarify: my number was for restart, not shutdown. Restart is a harder test. I'm satisfied.
(In reply to comment #42) > Just for reference, it still takes 22 seconds of 100% CPU usage to import the > Bookmarks.html file, so the task for fx3 has not diminished. I just want to note, that I was importing file with about 100 bookmarks and saw about 7000 database queries performed during the import. I did not fill bug for this yet, but will do so when I verify this.
I'm still getting long shutdowns (approximately 10 - 12 seconds) on a P3 933 MHz. The majority of this delay used to be with the bookmarks issue. Now that portion is fixed and that delay is now only about a second. The delay now is in closing the places.sqlite database. The delay in closing the database alone is 5 to 7 seconds (1.5 to 2 seconds in safemode). Below is a sample capture from Sysinternals Process Monitor: 9:43:11.8489936 AM firefox.exe 2956 UnlockFileSingle C:\Documents and Settings\...\Profiles\<insert>\places.sqlite SUCCESS 9:43:11.8493040 AM firefox.exe 2956 CloseFile C:\Documents and Settings\...\Profiles\<insert>\places.sqlite SUCCESS 9:43:16.6432297 AM firefox.exe 2956 CloseFile C:\Documents and Settings\...\Profiles\<insert>\permissions.sqlite SUCCESS Should I open a new bug for this issue?
(In reply to comment #46) > Should I open a new bug for this issue? Yes, please file a new bug for that and mention the bug number here.
For some reason, there seems to be a difference the first time one restarts Firefox. Either that or someone tweaked the performance of fx3 between the 2008-02-16 build and the -17 build. In any case, my 100% number is now 2 seconds on restart, and 1 second max on shutdown. I say 1 sec. max because at times the CPU usage does not even hit 100%.
(In reply to comment #47) > Yes, please file a new bug for that and mention the bug number here. Ok. Just filed Bug 418166
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
Component: Places → Bookmarks & History
QA Contact: places → bookmarks
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: