On Mon, 2011-03-21 at 22:28 +0000, Julian Foad wrote: > On Mon, 2011-03-21 at 17:23 -0400, C. Michael Pilato wrote: > > Recently (last week or so), I've noticed that 'svn commit' has gotten > > *really* slow. As in, it takes a full 30 seconds for 'svn commit' to return > > when asked to perform a no-op commit of my Subversion trunk directory. > > > > I was able to discern through code-stepping that the lion's share of the > > time spent was in the harvest_committables() code. I sorta suspected > > svn_wc__node_get_children_of_working_node() as the problem point, given that > > that's the only thing that's really changed in the harvest_committables() > > codepath recently, but I didn't really know how to verify that. > > > > So today I started trying to mess with callgrind a bit. Here's some heavily > > filtered output from callgrind_annotate on a no-op commit of just our > > trunk/subversion/tests/cmdline directory (committing at higher levels was > > taking FOREVER while profiling): > > > > 4,357,656,366 112,781 756 subversion/svn/main.c:main > > 4,352,930,262 112,657 753 subversion/svn/commit-cmd.c:svn_cl__commit > > 4,350,334,930 112,511 751 > > subversion/libsvn_client/commit.c:svn_client_commit5 > > 4,349,499,552 112,341 751 > > subversion/libsvn_client/commit_util.c:svn_client__harvest_committables > > 4,348,470,026 112,079 748 > > subversion/libsvn_client/commit_util.c:harvest_committables > > 4,269,103,898 108,354 729 > > subversion/libsvn_subr/sqlite.c:svn_sqlite__step > > 4,189,859,746 85,024 604 > > subversion/libsvn_wc/node.c:svn_wc__node_get_children_of_working_node > > 4,179,862,166 83,354 592 > > subversion/libsvn_wc/wc_db.c:svn_wc__db_read_children_of_working_node > > 4,179,834,710 83,354 592 > > subversion/libsvn_wc/wc_db.c:gather_children2 > > 4,179,798,573 83,354 592 > > subversion/libsvn_wc/wc_db.c:add_children_to_hash > > 4,046,859,894 116,411 761 > > subversion/libsvn_client/commit_util.c:harvest_committables'2 > > 90,828,539 16,308 85 > > subversion/libsvn_wc/wc_db.c:svn_wc__db_read_info > > 83,508,483 18,868 101 subversion/libsvn_wc/wc_db.c:read_info > > 32,672,951 492 6 > > subversion/libsvn_wc/wc_db_wcroot.c:svn_wc__db_wcroot_parse_local_abspath > > 29,042,308 3,196 17 > > subversion/libsvn_wc/wc_db.c:svn_wc__db_read_props > > 26,587,135 3,253 17 > > subversion/libsvn_wc/wc_db_txn.c:svn_wc__db_with_txn > > 26,561,409 3,253 17 > > subversion/libsvn_subr/sqlite.c:svn_sqlite__with_lock > > [...] > > > > I *think* this supports my hypothesis regarding > > svn_wc__node_get_children_of_working_node(). I have yet to try reverting > > the introduction of this function to see if that helps, but (because I'm out > > of time for today) I wanted to at least get this data out there for someone > > else to see. > > Ah, that would be me then. Bert mentioned just now on IRC that > "STMT_SELECT_WORKING_CHILDREN should perform a max(op_depth) on the > parent node or it might create a huge join which just returns the same > thing as the old gather children but then a lot slower". > > I think that's what I meant it to do but it looks like I forgot the > "max". Testing with a "max" now.
Bah, I think I misunderstood. I hadn't forgotten the "max", I had used the "nodes_current" view instead of "max". And you meant the use of "nodes_current" might create a huge join .... Thanks Bert for finding much more efficient ways today to do this. - Julian
