Johan,
I did a little more digging. There were a few different places where svn
seems to get hung up so I ran the gprof report on just the first one (the
merge takes hours otherwise). In this particular case, svn prints out that
it is merging from a small text file while it is hanging for more than a
minute @ 100% CPU. When I examine "lsof", however, it see it actually has a
different file open. This one is a large (15 MB) "binary" file. It turns
out this binary file did not have a property in the trunk (which I think
means it's treated as text, right?). But in the branch it was marked as
octet stream. So perhaps svn is doing a text-based diff on this binary
file because it used to be incorrectly marked as text?
Side-note: The contents of this 15MB file are actually ASCII, but we do want
it treated as binary b/c line-based merges are never valid.
Another snippet from the same gprof report is below.
Cheers,
Kyle
-----------------------------------------------
0.00 144.03 27/27 do_text_merge [10]
[11] 95.9 0.00 144.03 27 svn_diff_file_diff3_2 [11]
0.01 144.02 27/27 svn_diff_diff3_2 [12]
0.00 0.00 27/5723 apr_pool_destroy [833]
0.00 0.00 27/6430 svn_pool_create_ex [1558]
-----------------------------------------------
0.01 144.02 27/27 svn_diff_file_diff3_2 [11]
[12] 95.9 0.01 144.02 27 svn_diff_diff3_2 [12]
8.64 128.73 54/56 svn_diff(long, char, short)
[13]
0.01 5.09 21014/21014 svn_diff__resolve_conflict
[15]
0.03 1.51 81/81 svn_diff__get_tokens [25]
0.00 0.01 27/27 datasources_open [272]
0.01 0.00 81/85 svn_diff__get_token_counts
[284]
0.00 0.00 42065/2476341 apr_palloc [136]
0.00 0.00 27/27 svn_diff__tree_create
[1235]
0.00 0.00 54/5723 apr_pool_destroy [833]
0.00 0.00 27/27 token_discard_all [1282]
0.00 0.00 54/6430 svn_pool_create_ex [1558]
0.00 0.00 27/27 svn_diff__get_node_count
[1911]
-----------------------------------------------
0.32 4.77 2/56 svn_diff__resolve_conflict
[15]
8.64 128.73 54/56 svn_diff_diff3_2 [12]
[13] 94.8 8.96 133.49 56 svn_diff(long, char, short)
[13]
133.49 0.00 2002891836/2002891836 svn_diff__snake [14]
0.00 0.00 224/2476341 apr_palloc [136]
0.00 0.00 64/64 prepend_lcs [1103]
0.00 0.00 56/56 svn_diff__lcs_reverse
[1875]
-----------------------------------------------
133.49 0.00 2002891836/2002891836 svn_diff(long, char,
short) [13]
[14] 88.9 133.49 0.00 2002891836 svn_diff__snake [14]
0.00 0.00 168906/2476341 apr_palloc [136]
On Sun, Oct 2, 2011 at 5:58 PM, Johan Corveleyn <jcorvel_at_gmail.com> wrote:
> On Sun, Oct 2, 2011 at 11:08 PM, Kyle Leber <kyle.leber_at_gmail.com> wrote:
> > I was able to capture a profile from svn (after remembering I have to
> link
> > statically). I compiled with "-pg -O0" Here is the top of the file:
> >
> > Each sample counts as 0.01 seconds.
> > % cumulative self self total
> > time seconds seconds calls s/call s/call name
> > 88.88 133.49 133.49 2002891836 0.00 0.00 svn_diff__snake
> > 5.97 142.45 8.96 56 0.16 2.54 svn_diff(long,
> char,
> > short)
> > 1.98 145.42 2.97 4163001 0.00 0.00 MD5Transform
> > 0.41 146.04 0.62 4163001 0.00 0.00 Decode
>
> What's it doing in svn_diff__snake (or svn_diff for that matter)? That
> should only be hit when svn is doing textual merges (in which case it
> must do rather expensive diff calculations --- I'm sure those
> calculations can go ballistic when being confronted with a large
> binary file, not consisting of text lines).
>
> Are you sure those files were actually marked as binary (svn:mime-type
> of application/octet-stream or something else non-texty)?
>
> --
> Johan
>
Received on 2011-10-03 02:05:54 CEST