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.
Bert then said: "And just to be sure I think we should check if the
sqlite optimizer does the right thing, or that we should just perform
the retrieve parent_depth once before the entire query. (I would guess
it does the right thing)".
I'll take a look tomorrow.
- Julian
(hoping all it needs is the "max" to bring the speed back)
Received on 2011-03-21 23:29:11 CET