On Sat, Feb 05, 2011 at 01:11:28PM +0100, Stefan Sperling wrote:
> I'll look at profiler output. It has much better granularity.
I took 3 profiled runs of "svn pl -v -R" on an svn-trunk working copy
with and without the patch.
The results were pretty much the same for all runs.
The numbers below are from the second run.
The change has reduced the number of queries we issue,
but we are still issuing way too many queries for the impact to
be significant.
Before:
called/total parents
index %time self descendents called+self name index
called/total children
0.14 1.03 8467/8467 sqlite3Step [8]
[10] 55.2 0.14 1.03 8467 sqlite3VdbeExec [10]
[children of
sqlite3VdbeExec omitted]
% cumulative self self total
time seconds seconds calls ms/call ms/call name
22.7 0.48 0.48 _mcount [19]
12.3 0.74 0.26 __mcount [25]
10.4 0.96 0.22 478996 0.00 0.00 sqlite3BtreeMovetoUnpacked [18]
6.6 1.10 0.14 8467 0.02 0.14 sqlite3VdbeExec [10]
After:
called/total parents
index %time self descendents called+self name index
called/total children
0.17 1.07 4832/4832 sqlite3Step [8]
[9] 64.4 0.17 1.07 4832 sqlite3VdbeExec [9]
[again, children o
sqlite3VdbeExec omitted]
% cumulative self self total
time seconds seconds calls ms/call ms/call name
21.8 0.42 0.42 _mcount [18]
13.5 0.68 0.26 473315 0.00 0.00 sqlite3BtreeMovetoUnpacked [16]
8.8 0.85 0.17 4832 0.04 0.26 sqlite3VdbeExec [9]
8.8 1.02 0.17 __mcount [20]
The number of sqlite3VdbeExec() invocations has been reduced from 8467 to 4832.
But 4832 queries is still way too much when compared to not crawling
the tree at all. I don't have related gprof data anymore, but the log
message of r1039808 contains some hints:
gprof says this change speeds up "svn proplist -R svn-trunk-wc >/dev/null"
on my box from about 0.35s to about 0.11s. During profiled runs, the function
sqlite3Step() went from using 27% of the total time down to 15%. The time spent
within and below svn_client_proplist3() went down from 51% to 36%.
The profiler overhead accounted for about 31% of the total run time
before this change and about 45% after.
So, as expected, r1039808 had a much greater effect than r1066541.
Note that for our purposes sqlite3Step() is equivalent to sqlite3VdbeExec().
_mcount in the gprof output above shows the profiler overhead.
I think we should strongly consider revving affected callbacks in the
1.7 API and document restriction they have to heed. Then we can bring
the r1039808 code back. We can keep the code added in r1066541 for
backwards-compatibility if desired.
Stefan
Received on 2011-02-05 15:30:10 CET