405551 - investigate performance of AdjustIndices()

Status: RESOLVED FIXED

(Firefox :: Bookmarks & History, defect, P3)

Description

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

investigate performance of AdjustIndices()

in bug #405487, mano writes:  "Note inserting at the beginning of a folder may be very expensive due to AdjustIndicies."

I claim that with a folder with a lot of items, moving a item from the bottom to the top (or pasting a bookmark from the clipboard at the top), or cutting and undoing the top bookmark would expose perf issues.

I just tested with a folder of 600+ bookmarks on my mac debug build, it is worse "at the top" then at the bottom.

see also bug #404376

note, I haven't profiled, it might be something else (and not AdjustIndices()) that makes this slow.

Comment 1

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

making this depend on bug #404376, but note, I highly doubt it is our uncompiled sql statements that are the cause.  I just want to link the bugs together.

Comment 2

[Marco Bonardo [:mak]]

There is something bad in AdjustIndices, i mean: the first part of the function executes the UPDATE query, then there is a part that is building up a an array of RenumberItem structs using the mDBgetchildren SELECT query...

this array is not used anywhere. At the end the transaction get committed (it should be done after the update, not here).

then there is 
nsBookmarksUpdateBatcher batch;

this creates a batch update of nothing, the destructor get immediately executed, causing Bug 405521

now the function return NS_OK;

The update batch and the RenumberItem array were there to call this code, that now is missing:

  for (PRUint32 j = 0; j < mObservers.Length(); ++j) {                          
    const nsCOMPtr<nsINavBookmarkObserver> &obs = mObservers[j];                
    if (!obs) {                                                                 
      continue;                                                                 
    }                                                                           

    for (PRInt32 k = 0; k < items->Count(); ++k) {                              
      RenumberItem *item = NS_STATIC_CAST(RenumberItem*, (*items)[k]);          
      PRInt32 newPosition = item->position;                                     
      PRInt32 oldPosition = newPosition - aDelta;                               
      if (item->itemURI) {                                                      
        nsIURI *uri = item->itemURI;                                            
        obs->OnItemMoved(uri, aFolder, oldPosition, newPosition);               
      } else if (item->folderChild) {                                           
        obs->OnFolderMoved(item->folderChild, aFolder, oldPosition,             
                           aFolder, newPosition);                               
      }                                                                         
    }                                                                           
  }   

this has been removed between 1.51 and 1.52 with Bug 329892

Could someone take a look at the function and tell me if i'm wrong?

Comment 3

[Marco Bonardo [:mak]]

Attachment: remove unused code

if my previous analysis is right, and that code is no more useful in current implementation, this patch removes unused code bits. 
atm i have not find any problem reordering bookmarks with this patch checked in.

Comment 4

[Dietrich Ayala (:dietrich)]

(In reply to comment #3)
> Created an attachment (id=290388) [details]
> remove unused code
> 
> if my previous analysis is right, and that code is no more useful in current
> implementation, this patch removes unused code bits. 
> atm i have not find any problem reordering bookmarks with this patch checked
> in. 
> 

"make check" fails with this patch

Comment 5

[Marco Bonardo [:mak]]

Comment on attachment 290388 [details] [diff] [review]
remove unused code

investigating, can't see what could cause a test to fail here...
hwv i will need to include also nsNavBookmarks.h patch, so i'm marking obsolete this for now

Comment 6

[Marco Bonardo [:mak]]

Attachment: remove unused code

sorry for late, i had to clean up my tree...

i have compiled the current trunk source and launched make check, all ok
then i've added my patch, build, make check, everything still passed... what test failed on your side?

Comment 7

[Dietrich Ayala (:dietrich)]

still failing with this patch applied. my test failure log:

../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js: /Users/dayala/moz/newplaces/mozilla/tools/test-harness/xpcshell-simple/test_all.sh: line 129: 22322 Abort trap              NATIVE_TOPSRCDIR="$native_topsrcdir" TOPSRCDIR="$topsrcdir" $xpcshell -s $headfiles -f $t $tailfiles 2>$t.log 1>&2
FAIL
../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js.log:
>>>>>>>
nsNativeModuleLoader::LoadModule("/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libeditor.dylib") - load FAILED, rv: 80004005, error:
        Unknown error: -2804
*** Registering components in: nsPlacesModule
*** registering nsTaggingService.js: [ Places Tagging Service ]
../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: trailing comma is not legal in ECMA-262 object initializers:
../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: };

../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: ^
*** test pending
*** PLACES TESTS: test setItemTitle
*** PLACES TESTS: dateAdded = 1196709886290551
*** PLACES TESTS: beforeSetTitle = 1196709886293000
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196709886294304
*** PLACES TESTS: test setKeywordForBookmark
*** PLACES TESTS: dateAdded = 1196709886326047
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196709886327040
*** PLACES TESTS: bookmark itemId test: CC = 7
*** PLACES TESTS: test changeBookmarkURI
*** PLACES TESTS: dateAdded = 1196709886337521
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196709886338608
WARNING: history observers should not get OnItemChanged, but should get the corresponding history notifications instead: file /Users/dayala/moz/newplaces/mozilla/toolkit/components/places/src/nsNavHistoryResult.cpp, line 2668
WARNING: history observers should not get OnItemChanged, but should get the corresponding history notifications instead: file /Users/dayala/moz/newplaces/mozilla/toolkit/components/places/src/nsNavHistoryResult.cpp, line 2668
###!!! ASSERTION: history observers should not get OnItemVisited, but should get OnVisit instead: 'Not Reached', file /Users/dayala/moz/newplaces/mozilla/toolkit/components/places/src/nsNavHistoryResult.cpp, line 2679
nsNavHistoryContainerResultNode::SortComparison_VisitCountGreater(nsNavHistoryResultNode*, nsNavHistoryResultNode*, void*)+0x00000260 [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libplaces.dylib +0x0003CE1C]
nsNavHistoryQueryResultNode::OnRemoving()+0x0000065D [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libplaces.dylib +0x000486CB]
nsNavBookmarks::nsNavBookmarks()+0x0000120F [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libplaces.dylib +0x000571C9]
nsNavHistory::BeginUpdateBatch()+0x000025B7 [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libplaces.dylib +0x0002DAD7]
NS_InvokeByIndex_P+0x00000062 [../../../../dist/bin/libxpcom_core.dylib +0x00078ACC]
XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode)+0x000016E0 [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libxpconnect.dylib +0x00040032]
XPC_WN_CallMethod(JSContext*, JSObject*, unsigned int, long*, long*)+0x0000018E [/Users/dayala/moz/newplaces/build-dbg/dist/bin/components/libxpconnect.dylib +0x00047ABE]
js_Invoke+0x00000BF7 [../../../../dist/bin/libmozjs.dylib +0x0005BCE2]
js_Interpret+0x0001008F [../../../../dist/bin/libmozjs.dylib +0x0006D63B]
js_Execute+0x000003E2 [../../../../dist/bin/libmozjs.dylib +0x0005C669]
JS_ExecuteScript+0x00000082 [../../../../dist/bin/libmozjs.dylib +0x000185E3]
tart+0x00001799 [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x00001FF5]
tart+0x00001AD6 [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x00002332]
tart+0x0000212C [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x00002988]
main+0x00000894 [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x00003C24]
tart+0x00000102 [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x0000095E]
tart+0x00000029 [/Users/dayala/moz/newplaces/build-dbg/toolkit/components/places/tests/../../../../dist/bin/xpcshell +0x00000885]

<<<<<<<

Comment 8

[Marco Bonardo [:mak]]

i'm not running tests in debug mode, i'll try it now, will that change the test results? could that be connected to the fact i'm building in Windows? 
I can't see any modification to observers in the touched code, it's a mere query that adds results to an array of structs... 

my test_bookmarks.log is PASS

*** test pending
*** PLACES TESTS: test setItemTitle
*** PLACES TESTS: dateAdded = 1196728462929785
*** PLACES TESTS: beforeSetTitle = 1196728462929000
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196728462929785
*** PLACES TESTS: test setKeywordForBookmark
*** PLACES TESTS: dateAdded = 1196728462949814
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196728462949814
*** PLACES TESTS: bookmark itemId test: CC = 7
*** PLACES TESTS: test changeBookmarkURI
*** PLACES TESTS: dateAdded = 1196728462959828
*** PLACES TESTS: lastModified = 0
*** PLACES TESTS: lastModified2 = 1196728462959828
*** PLACES TESTS: check that the folder was created with a valid dateAdded
*** PLACES TESTS: beforeCreate = 1196728462969000
*** PLACES TESTS: dateCreated = 1196728462969843
*** PLACES TESTS: check that the separator was created with a valid dateAdded
*** PLACES TESTS: beforeInsert = 1196728462969000
*** PLACES TESTS: dateAdded = 1196728462969843
*** test finished
*** exiting
*** PASS ***
../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: trailing comma is not legal in ECMA-262 object initializers:
../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: };

../../../../_tests/xpcshell-simple/test_places/bookmarks/test_bookmarks.js:104: strict warning: ^

Comment 9

[Dietrich Ayala (:dietrich)]

i probably need to do a clobber build. i'm seeing failures in other areas now, which aren't at all related.

Comment 10

[Dietrich Ayala (:dietrich)]

Comment on attachment 290865 [details] [diff] [review]
remove unused code

r=me, this looks fine.

Comment 11

[Marco Bonardo [:mak]]

Comment on attachment 290865 [details] [diff] [review]
remove unused code

asking approval, since this is not blocking yet

Comment 12

[Marco Bonardo [:mak]]

thank you, this is checkin-needed, i think that after the checkin the bug should be leaved open for further investigation from seth and mano that had discussion on this perf problem

Comment 13

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

I'm about to land this, but I see the same test failures as dietrich, so I'll also land a change to clobber tbox.

Comment 14

[Reed Loden [:reed]]

Please note that "checkin-needed" is a keyword, not part of the status whiteboard. People such as myself will not see this bug as needing a commit if it's not put in the "keywords" field. :)

Removing it for now, as sspitzer is going to take care of this.

Comment 15

[Dietrich Ayala (:dietrich)]

I pulled a fresh tree, rebuilt, and this is still failing the same test. Might be worth checking in to see what the error in the tinderbox is, but I'm having doubts that this is just my box.

Comment 16

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

> I pulled a fresh tree, rebuilt, and this is still failing the same test.

me too, this is not safe to land yet.

Comment 17

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

Comment on attachment 290865 [details] [diff] [review]
remove unused code

obsoleting until we figure this one out.

Comment 18

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

dietrich, earlier today you marked this p3 / m10.

I assume that is for the perf issue, and not the code removal?

Comment 19

[Marco Bonardo [:mak]]

ok, i'm able to reproduce test fail, on my machine that fails in debug mode, while it PASS in optimized mode...

Comment 20

[Marco Bonardo [:mak]]

Attachment: remove unused code, but retain batchupdate

i get the failing here in test_bookmarks.js:

  // bug 378820
  var uri1 = uri("http://foo.tld/a");
  bmsvc.insertBookmark(testRoot, uri1, bmsvc.DEFAULT_INDEX, "");
  histsvc.addVisit(uri1, Date.now(), 0, histsvc.TRANSITION_TYPED, false, 0);

inverting the last 2 lines solves the problem, but also readding back nsBookmarksUpdateBatcher fixes the problem, maybe because mBatchInProgress is set to true and many functions returns NS_OK in that case (not calling observers)

i'm taking the second way, adding nsBookmarksUpdateBatcher before the update query. this pass the test also in debug mode

Comment 21

[Marco Bonardo [:mak]]

Attachment: same as above

oops, i had forgot to remove the transaction start

Comment 22

[Adam Kowalczyk]

Marco, if I understand things correctly then keeping nsBookmarksUpdateBatcher just works around a deeper problem. Creating a batch update here doesn't make any sense from the observer's point of view and it shouldn't be necessary - see bug 405521.

Comment 23

[Marco Bonardo [:mak]]

yes, there is something not working in observers that it's not clear to me (sorry i'm a volunteer and i'm still learning :) ), however i've moved updatebatcher above the query to create the transaction before and have something back, this is still faster than before. 

hwv i think that bug 405521 is still valid until someone finds what's the deeper problem.

Comment 24

[Dietrich Ayala (:dietrich)]

Comment on attachment 291465 [details] [diff] [review]
same as above

this is fine for now. let's tackle the batchupdate problem in the other bug.

Comment 25

[Reed Loden [:reed]]

Checking in toolkit/components/places/src/nsNavBookmarks.cpp;
/cvsroot/mozilla/toolkit/components/places/src/nsNavBookmarks.cpp,v  <--  nsNavBookmarks.cpp
new revision: 1.136; previous revision: 1.135
done

Comment 26

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

marco / dietrich:  the code cleanup got landed, but I don't think the original issue (as reported in comment #0) has been addressed.

Re-opening bug.

Comment 27

[Marco Bonardo [:mak]]

this however removed a cycle, a select query, and some memory assignments. So it should be faster, about as a single update query.

Comment 28

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

Thanks Marco.  I'll re-test what I did in commment #0, and if there doesn't appear to be a "worse at top" performance problem, I'll mark this bug as fixed.

Comment 29

[Mike Schroepfer]

Should this be closed?

Comment 30

[Dietrich Ayala (:dietrich)]

did some quick testing - in a folder of 70+ bookmarks, dropping a bookmark at the top did seem to take longer than dropping at the bottom.

Comment 31

[Marco Bonardo [:mak]]

i want to take a look at this when i'll have the time, i hope that adjustindices can be fixed so that it has about the same cost in every position (but should check a couple of things before)

Comment 32

[Marco Bonardo [:mak]]

i think that we cannot do anything more here, i thought that we could somehow change AdjustIndices to automatically fix indexes only knowing parent and position. Probably that would be feasable, but will not apport any perf gain, and actual code is enough generic to be reused (and we are already taking in count perf for movements between the same container, or adding to the bottom). 

Dropping at the bottom does not require really any change to the db since you are adding a new index, and you don't have to update anything, while dropping at the top requires all following indexes to be  updated (to add +1). So most probably the backend cannot do anything to be faster, the slowlyness is due to disk access to update all followers, and to js code that recalculate indexes in the treeView.

Comment 33

[Marco Bonardo [:mak]]

marking as fixed. we should investigate js treeview performance if the slowdown will come back.

Comment 34

[Gervase Markham [:gerv]]

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