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
Received on 2011-03-22 14:41:18 CET