373256 - URL/location bar autocomplete slowness (sqlite database doesn't seem to be cached)

Status: RESOLVED FIXED

(Firefox :: Address Bar, defect, P2)

Description

[Kingsly John]

User-Agent:       Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9a3pre) Gecko/20070223 Minefield/3.0a3pre
Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9a3pre) Gecko/20070223 Minefield/3.0a3pre

(Not sure if this is a bug or expected behaviour... but it's a mixed bag in the upgrade from 2.0 to 3.0alpha)

I have a fairly large history(~60MB places.sqlite), in fx2.0 and earlier the history feature was pretty much unusable(too slow , too much memory) due to the large size. But the URL auto-completion in the address/location field worked fine with a pause of maybe a couple of seconds(which was acceptable for the volume of data).

In Fx3.0 thanks to sqlite , the history feature (Ctrl-H) is finally usuable, (a LOT faster than before)

But the URL autocompletion has slowed down like crazy, the UI freezes for many seconds (20-30 seconds on average sometimes as high as a minute.) after I type the first letter. During which time there is plenty of disk activity(a constant read of ~600kb/sec) and minimal CPU activity.

Trying to go to a URL started with a different letter immediately after this results in a similiar amount of delay.

I have plenty of free RAM but the sqlite database doesn't seem to be cached. And is being read from disk again even though it hasn't been modified.

But the latest query results seem to be cached and typing the same character again shows up the auto-complete options almost instantly.

Similarly for the history too , hitting Ctrl-H ...results in the database being read from disk .. and then high CPU activity while the history tree is being generated.

Closing the history sidebar and immediately hitting Ctrl-H a second time, results in data being read from disk once again and then high CPU load as the history tree is generated again.


Reproducible: Always

Steps to Reproduce:
1. Start with a large history file (places.sqlite > 60MB)
2. hit the first letter to a URL, (say "p")
3. (long pause while auto-complete information is being retreived, UI freezes/browser is unresponsive, constant disk activity around 600kb/sec)

-- continuing on--

4. Do not go to any site, instead clear the typed letter "p" and change it to "s"
5. (another long pause and UI freezes while auto-complete information is being retreived, similiar disk activity as in step 3)

(Note in all this while there has been no browsing so places.sqlite is unchanged)

6. clear the location bar and and type the original character in step 2 (ie, "p")
7. auto complete options show up instantly.
Actual Results:  
UI freezes in steps 3 and 5 

Expected Results:  
1. UI shouldn't freeze while waiting for auto-complete.
2. Autocomplete should be instantaneous atleast after the history database has been read once. History database shouldn't have to be read 26 times for each starting letter.

Comment 1

[Dave Townsend [:mossop]]

I see this all the time myself and it makes typing urls extremely painful. It appears that the first time you type a letter as the first letter in the url bar during a browser session the entire browser pauses as it looks up the entries starting with that letter.

Comment 2

[Mike Connor [:mconnor]]

Probably just a DB optimization issue, iirc it wasn't tuned way back when.

Comment 3

[Mike Connor [:mconnor]]

Seth, can you take a look here?

Comment 4

[(not reading, please use [e-mail] instead)]

adam, is this the bug you mentioned at dinner (last week) with Stephen Donner?

Comment 6

[Adam Guthrie]

Yep, this is the one, Seth.

Comment 7

[(not reading, please use [e-mail] instead)]

Adam writes:  

> apparently you have to be using the build for a while to experience the autocomplete hang bug.

But I think mossop can reproduce this at will.

Comment 8

[Mike Connor [:mconnor]]

Dave, can you try to catch this in a profiler (i.e. Shark) and see what's up?

Comment 9

[(not reading, please use [e-mail] instead)]

I have the places.sqlite from mossop, ispiked and bsmedberg and so far, while I can definitely see slowness with large histories , I don't see the super slow behaviour.

but interesting comment from ria, from bug #385397 comment #3:

"The delays while scrolling and while typing in the location bar only happen
after opening the History menu. Then it gets worse and worse and the only
solution is to restart the browser and to avoid the use of the History menu."

investigating that now.

Comment 10

[Dave Townsend [:mossop]]

Attachment: Stack trace from spin control

Haven't had chance to install and play with shark, will try that later this afternoon.

For the mean time found spin control which manages to do a quick job of giving stack traces with the time spent during the hang, this is the output.

Comment 11

[Dave Townsend [:mossop]]

Attachment: Filtered view

This is the same result but I've just cut out the stack trace that looks to be involved. Perhaps unsurprisingly the majority of the time is spent in sqlite

Comment 12

[(not reading, please use [e-mail] instead)]

Dave, is attachment #270156 [details] really a call stack?  I'm a little confused by the output.

Comment 13

[(not reading, please use [e-mail] instead)]

myk is seeing this as well, with his 99 days of history (or so).

a few thoughts:

1)  I have added some timing code in my tree, and with ispiked's large places.sqlite, I have seen some one letter queries take 2.5+ seconds.  But subsequent queries are fast.  perhaps what I am seeing here is related to bug #385066?

2)  separate from finding and fixing this perf bug, it seems like we fire the search too fast upon typing.  (my experience here is anecdotal.)  

Right now, I think the timeout is set to 50 ms (the default).  See also http://lxr.mozilla.org/seamonkey/search?string=timeout%3D%2522

Are there any UE guidelines here?

Comment 14

[(not reading, please use [e-mail] instead)]

additionally, mano's fix for bug #386159 should have an impact here as we should not be rebuilding the history menu (on the lazy add timer) which could very expensive.

Comment 15

[Alex Faaborg [:faaborg] (Firefox UX)]

>Are there any UE guidelines here?

If the user is expecting something to happen, you have between 50 and 200 ms to do it or the interface will feel sluggish.

For instance, if you click on the stop button, and it takes longer than 50 ms to draw the depressed state, the interface will feel slow.

Auto-complete is a little different in that the user is not necessarily expecting it to respond immediately.  But for instance, once you draw the drop down, you need to populate the results in 50 ms or it will feel slow.

Comment 16

[Dave Townsend [:mossop]]

(In reply to comment #12)
> Dave, is attachment #270156 [details] really a call stack?  I'm a little confused by the
> output.

I'm going to try this again today with a debug build, I'm not sure if the non-debug build I was using has thrown this off.

(In reply to comment #13)
> 2)  separate from finding and fixing this perf bug, it seems like we fire the
> search too fast upon typing.  (my experience here is anecdotal.)  
> 
> Right now, I think the timeout is set to 50 ms (the default).  See also
> http://lxr.mozilla.org/seamonkey/search?string=timeout%3D%2522

I think this is probably far too low. I'm a pretty fast typer and it's not difficult to type "www" very quickly. And yet I still seem have autocomplete catching and building the results after the first w.

Comment 17

[Myk Melez [:myk] [@mykmelez]]

I have the same experience as mossop.  Although I can type very fast, I can't outrace the timer, which makes typing unresponsive the moment I type the first character.

But I don't think the solution is to slow the timer down unless there's no way to improve the performance of the query, since 50ms works fine with a cached query.  For example, if I type "w" and then wait a few seconds for the query to get retrieved and cached, then the next time I type "w", autocomplete pops up instantaneously without interfering with my typing, which is as it should be.

So I think the ideal thing to do would be to keep the timer at 50ms but find a way to improve the performance of the query.  If that's not possible, however, or if we optimize the query as much as possible, and it's still too slow, then increasing the timer may help.

Comment 18

[Dave Townsend [:mossop]]

I think a combination really. I imagine the query is never going to be instantaneous so we should only be doing it when the user pauses during typing.

Comment 19

[Dave Townsend [:mossop]]

Attachment: Shark time profile

This is a time profile taken with shark of just the autocomplete slowness. Attached is a text grab of the main part, the full profile can be downloaded from http://users.blueprintit.co.uk/~dave/testcases/bug373256/profile.zip

Comment 20

[Dave Townsend [:mossop]]

Forgot to add this is from a debug build and I think shows more sensible results than the previous traces.

Comment 21

[Shawn Wilsher :sdwilsh]

(In reply to comment #19)
> Created an attachment (id=270720) [details]
> Shark time profile
It looks to me like we are spending way too long processing the results.  I think this because we are spending a very large time calling executeStep.

Comment 22

[Dave Townsend [:mossop]]

Forgot to add, Seth if you wanted to attach your timing stuff then I could include it in a build and give you some results from my machine too if that's any good to you.

Comment 23

[(not reading, please use [e-mail] instead)]

for reference:

<sspitzerMsgMe> about the url performance problems, you seem to hit it every time?
<Mossop> No and I haven't really narrowed down when it happens. Sometimes its the first time I use the url bar after startup, sometimes it's after the browsers been running for a while. It always only happens once before it clears up for a while though.

Comment 24

[Brett Wilson]

If your places.sqlite file is larger than the history cache size allowed for your machine, you'll get horrible performance on this. Once you've don't 'a', you've loaded all the A's and it will be fast for a while until something evicts it.

You'll also get horrible page load performace because link coloring queries will randomly hit disk. Have you run PLT on such a history database?

This is very bad! Under normal usage, the entire database MUST fit in the cache for reasonable performance across the board. You either need to increase the percentage of memory that can be used for the cache, keep history smaller, or somehow only do autocomplete and link coloring queries on a smaller database. There is really no other option.

FWIW, I think the case insensetive like query in bug 389491 will make this much worse since it will force a full table scan for EVERY query.

Comment 25

[patrickdrd]

I have many history entries in ie too,
when I start typing sth in ie address bar it takes some time to load the history entries that start from the words I type, but ie is responding to anything else I do (does that in the background somehow), while fx becomes unresponsive (I can't do anything else)

Comment 26

[Radek 'sysKin' Czyz]

A somehow related suggestion: When I type "w", it would appear that sqlite accesses favicons for all autocomplete results (which is pretty much all favicons of all websites ever) while only 14 favicons are actually displayed (unless I scroll).

Perhaps limiting favicons to only the ones currently visible will reduce the sqlite's output and also number of queries?

Do you want me to file a separate bug for that?

Comment 27

[Steve Krulewitz]

We have a similar search requirements in Songbird -- for us, the problem is simply that a full substring search ("LIKE '%search%'") can not use an index.  I wonder if we could create a custom index type in sqlite that could improve the performance of this type of query?

Comment 28

[Myk Melez [:myk] [@mykmelez]]

(In reply to comment #27)
> We have a similar search requirements in Songbird -- for us, the problem is
> simply that a full substring search ("LIKE '%search%'") can not use an index. 
> I wonder if we could create a custom index type in sqlite that could improve
> the performance of this type of query?

You could use a fulltext index.  It's not a full substring search, but it's fast and effective for searches whose terms start at the beginnings of words (perhaps the large majority of searches), and it should be possible to do a performant substring search on the terms in a fulltext index (although I'm not sure if this is possible with the built-in fulltext indexing capabilities in SQLite), which also isn't a "full" substring search but may be close enough.

Comment 29

[risto.kankkunen]

I have pretty similar experiences as John. I have a 400 day history, history.dat was 18 MB and places.sqlite is 35 MB. Like John, I found Fx 2 unbearable to use, every action that updated history (opening a new page, downloading etc.) took ages with CPU at 100%. While the initial start of 3.0a7 took >10 minutes (places conversion?), after that it seems faster. Process size is maybe a bit smaller, too (about 310MB vs. 380MB, but the latter figure was after Fx had been on for weeks, so it's not comparable as the size keeps growing over time...)

The biggest problem is the looong pause after typing the 1st letter on address bar.

I don't want the full history data to be cached in memory, Fx is already taking too much of it. However, I'm wondering are you really fetching all the entries in a single query rather than in chunks? Instead of

  SELECT * FROM tbl WHERE address LIKE 'a%'

why not

  SELECT * FROM tbl WHERE address LIKE 'a%' LIMIT 15

If the user actually needs to see more, fetch additional entries with suitable OFFSET. I guess you could even time how long it took to fetch a chunk and adapt the chunk size based on that...

If this doesn't help, or if you are already doing this, maybe the query should be done in a background thread. Autocomplete should help the user, now it's in the way...

Comment 30

[risto.kankkunen]

FYI: I had noticed a while ago that the autocomplete results were appearing faster and they seemed to come incrementally, like I proposed above, and the user experience is much better.

I was expecting a note to appear here to tell that some code changes had been done. But now when I checked the thing a little bit closer I noticed that my history setting had been changed from 400 to 180 days, without my knowledge!

Places.sqlite is up from 35 MB to 40 MB, but I guess the file size does not necessarily reflect the number of entries (maybe I should do SELECT COUNT(*) FROM sometable?).

If there have been no other changes, I guess reducing the history to 180 days decreased the item count enough that in my configuration most of the relevant data is now in memory and that results in the perceived multifold speed increase.

I have changed the history length back to 400 days now. I may report how it affects the issue in about 220 days...

Comment 31

[(not reading, please use [e-mail] instead)]

sliding to m11, but this needs to be re-evaluated

Comment 32

[Dietrich Ayala (:dietrich)]

un-assigning seth's places/autocomplete bugs.

Comment 33

[Ed Lee :Mardak]

Is this still an issue with the latest trunk now that global frecency (bug 394038) landed and various perf followup fixes to it (bug 414229).

Comment 34

[Stephen Donner [:stephend] Not actively reading bugmail]

(In reply to comment #33)
> Is this still an issue with the latest trunk now that global frecency (bug
> 394038) landed and various perf followup fixes to it (bug 414229).

Seems pretty fast to me, but I'm on a MacBook Pro :-)  Still, mark it as FIXED, I'd think, and we can file more-specific bugs.

Comment 35

[u251854]

My places.sqlite file is only about 2 MB (with default preferences), but I've been suffering badly because of this bug.
We should get this fixed before Fx 3.0 release or at least make the location bar more usable.

Comment 36

[Dietrich Ayala (:dietrich)]

(In reply to comment #35)
> My places.sqlite file is only about 2 MB (with default preferences), but I've
> been suffering badly because of this bug.
> We should get this fixed before Fx 3.0 release or at least make the location
> bar more usable.
> 

Can you please provide your build information?

Comment 37

[u251854]

Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9b4pre) Gecko/2008021404 Minefield/3.0b4pre

Location bar has improved for me in latest nightlies and now it hangs for 2-3 seconds when typing the first letter. I don't know if it is intended or can it be improved a little more. After all my places.sqlite isn't so big.

Comment 38

[Brett Wilson]

(In reply to comment #37)
> Location bar has improved for me in latest nightlies and now it hangs for 2-3
> seconds when typing the first letter. I don't know if it is intended or can it
> be improved a little more. After all my places.sqlite isn't so big.

This sounds like a problem caused by bug 385066.

Comment 39

[Ed Lee :Mardak]

(In reply to comment #37)
> Location bar has improved for me in latest nightlies and now it hangs for 2-3
> seconds when typing the first letter.
Is this the first letter of the first time you start the app? Or is it every time you type a single letter?

Comment 40

[u251854]

(In reply to comment #39)
> Is this the first letter of the first time you start the app? Or is it every
> time you type a single letter?
> 
Every time. 

Comment 41

[Mike Connor [:mconnor]]

Since everyone except Mateusz seems to have this issue resolved, going to resolve this bug and ask him to file a followup with specific details to look at his specific issue, since I don't think its the preloading issue at all.

Comment 42

[Robert Sayre]

I still see this too.

Comment 43

[Ed Lee :Mardak]

Could you try this build and report back if it's any better or worse?

https://build.mozilla.org/tryserver-builds/2008-03-16_18:[e-mail]/

Comment 44

[Ed Lee :Mardak]

Mateusz: Does that build make things worse or not? Or you don't see the problem anymore, so we can WFM. Unless someone else says it's not WFM and check if the build I posted in comment #43 helps or not..

Comment 45

[u251854]

Your build is slightly better when typing more than one letter - it seems to show address faster by about 100 ms, but it's my own feeling so I can be wrong.

The official build doesn't hang anymore (tested on Mozilla/5.0 (X11; U; Linux i686; pl; rv:1.9b5pre) Gecko/2008031804 Minefield/3.0b5pre). So I guess it's WFM.

Comment 46

[Ed Lee :Mardak]

I'm marking this fixed now that several bugs have been fixed recently: bug 422177, bug 424388, bug 422491, bug 422490, bug 406257 as well as some from before: bug 406359, bug 415489, bug 414507, bug 414229, bug 407429.

Comment 47

[Martijn Wargers (dead)]

It seems faster (afaict) than older trunk builds, but it's certainly not as fast as the old url bar autocomplete.
I guess it's now quick enough then.