[viewvc-dev] ViewVC 1.1.13 viewvc.get_result tricked by unusually long patch message
"Robert C. Kahlert" <[email protected]> Fri, 30 Mar 2012 14:00:06 -0500
| Newsgroups | gmane.comp.version-control.cvs.viewcvs.devel |
|---|---|
| Message-ID | <CAGgsKjw5tCysvnG7v_jEqEbsdpru+2hKQX-zSyTwDH0CxYn57Q@mail.gmail.com> |
------=_Part_5452_1008044925.1333134266364
Content-Type: text/plain; charset=us-ascii
Content-Transfer-Encoding: 7bit
Hi,
this may or may not be the right list to report this problem to, so
apologies if it is not.
We are running into a situation with ViewVC 1.1.13 where the get_result()
method in viewvc.py (line 1210) is being bitten by an update with a very
long VC log message (~250K).
Specifically, the maxlen parameter does not seem to be passed down to the
self._tokenize_text() method, which is going to town on the 250K message,
calling the search method millions of times, for emitting a few hundred
characters in the summary view.
Here are some python profiling results for one folder with 100 files, and
for one with 1000 files (which, sad to say, reflect true examples from our
repository). The first takes 30 seconds to render, the second over 4
minutes (!).
(A) The Directory with one hundred files
15997575 function calls (15991810 primitive calls) in 31.856 CPU
seconds
Ordered by: internal time
List reduced from 989 to 99 due to restriction <0.10000000000000001>
ncalls tottime percall cumtime percall filename:lineno(function)
3788767 17.651 0.000 17.651 0.000 {built-in method search}
228 6.709 0.029 27.035 0.119 viewvc.py:1232(_tokenize_text)
632512 1.232 0.000 3.002 0.000 sapi.py:35(escape)
1263162 1.056 0.000 2.273 0.000 viewvc.py:4550(__init__)
2530277 1.046 0.000 1.843 0.000 string.py:511(replace)
228 0.843 0.004 31.431 0.138 viewvc.py:1210(get_result)
2530283 0.797 0.000 0.797 0.000 {method 'replace' of 'str'
objects}
1263164 0.625 0.000 0.625 0.000 {vars}
1263177 0.591 0.000 0.591 0.000 {method 'update' of 'dict'
objects}
631794 0.481 0.000 3.552 0.000 viewvc.py:1187(format_text)
1268335 0.190 0.000 0.190 0.000 {method 'append' of 'list'
objects}
600 0.142 0.000 0.142 0.000 {method 'split' of 'str'
objects}
118 0.079 0.001 0.093 0.001 {_fs.svn_fs_check_path}
637068/636957 0.074 0.000 0.074 0.000 {len}
(B) The Directory with one thousand files
133750340 function calls (133704141 primitive calls) in 269.160
CPU seconds
Ordered by: internal time
List reduced from 1002 to 100 due to restriction <0.10000000000000001>
ncalls tottime percall cumtime percall filename:lineno(function)
31701892 147.583 0.000 147.583 0.000 {built-in method search}
2087 58.027 0.028 228.247 0.109 viewvc.py:1232(_tokenize_text)
5293057 10.545 0.000 25.366 0.000 sapi.py:35(escape)
10569433 8.868 0.000 19.292 0.000 viewvc.py:4550(__init__)
21174316 8.785 0.000 15.433 0.000 string.py:511(replace)
2087 7.067 0.003 265.489 0.127 viewvc.py:1210(get_result)
21174322 6.648 0.000 6.648 0.000 {method 'replace' of 'str'
objects}
10569448 5.270 0.000 5.270 0.000 {method 'update' of 'dict'
objects}
10569435 5.154 0.000 5.154 0.000 {vars}
5286693 4.238 0.000 30.173 0.000 viewvc.py:1187(format_text)
10586140 1.573 0.000 1.573 0.000 {method 'append' of 'list'
objects}
3363 1.171 0.000 1.171 0.000 {method 'split' of 'str'
objects}
46995 0.761 0.000 0.761 0.000 {method 'write' of 'file'
objects}
1021 0.649 0.001 0.784 0.001 {_fs.svn_fs_check_path}
5298333/5298222 0.611 0.000 0.611 0.000 {len}
Obviously, this situation (large folder, unusually large patch message) is
an edge case; but the situation should be easy to replicate and the
solution equally straight-forward.
Two ideas come to mind:
(a) pre-truncating the message (e.g. to 10 x the max len intended, to pick
a heuristic)
(b) caching the tokenization summary, since patches usually affect multiple
files
Either solution would fix our situation.
Best
Robert C. Kahlert
Senior Programmer Analyst
Cycorp Inc (http://www.cyc.com)
7718 Wood Hollow Drive, Suite #250
------------------------------------------------------
http://viewvc.tigris.org/ds/viewMessage.do?dsForumId=4251&dsMessageId=2942585
To unsubscribe from this discussion, e-mail: [[email protected]].
------=_Part_5452_1008044925.1333134266364
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable
Hi,<br><br>this may or may not be the right list to report this problem to,=
so apologies if it is not.<br><br>We are running into a situation with Vie=
wVC 1.1.13 where the get_result() method in viewvc.py (line 1210) is being =
bitten by an update with a very long VC log message (~250K).<br>
<br>Specifically, the maxlen parameter does not seem to be passed down to t=
he self._tokenize_text() method, which is going to town on the 250K message=
, calling the search method millions of times, for emitting a few hundred c=
haracters in the summary view.<br>
<br>Here are some python profiling results for one folder with 100 files, a=
nd for one with 1000 files (which, sad to say, reflect true examples from o=
ur repository). The first takes 30 seconds to render, the second over 4 min=
utes (!).<br>
<br>(A) The Directory with one hundred files<br><br><span style=3D"font-fam=
ily:courier new,monospace">=A0=A0=A0=A0=A0=A0=A0=A0 15997575 function calls=
(15991810 primitive calls) in 31.856 CPU seconds</span><br style=3D"font-f=
amily:courier new,monospace">
<br style=3D"font-family:courier new,monospace"><span style=3D"font-family:=
courier new,monospace">=A0=A0 Ordered by: internal time</span><br style=3D"=
font-family:courier new,monospace"><span style=3D"font-family:courier new,m=
onospace">=A0=A0 List reduced from 989 to 99 due to restriction <0.10000=
000000000001></span><br style=3D"font-family:courier new,monospace">
<br style=3D"font-family:courier new,monospace"><span style=3D"font-family:=
courier new,monospace">=A0=A0 ncalls=A0 tottime=A0 percall=A0 cumtime=A0 pe=
rcall filename:lineno(function)</span><br style=3D"font-family:courier new,=
monospace"><span style=3D"font-family:courier new,monospace">=A0 3788767=A0=
=A0 17.651=A0=A0=A0 0.000=A0=A0 17.651=A0=A0=A0 0.000 {built-in method sear=
ch}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0=A0 228=A0=A0=
=A0 6.709=A0=A0=A0 0.029=A0=A0 27.035=A0=A0=A0 0.119 viewvc.py:1232(_tokeni=
ze_text)</span><br style=3D"font-family:courier new,monospace"><span style=
=3D"font-family:courier new,monospace">=A0=A0 632512=A0=A0=A0 1.232=A0=A0=
=A0 0.000=A0=A0=A0 3.002=A0=A0=A0 0.000 sapi.py:35(escape)</span><br style=
=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0 1263162=A0=A0=A0 1.05=
6=A0=A0=A0 0.000=A0=A0=A0 2.273=A0=A0=A0 0.000 viewvc.py:4550(__init__)</sp=
an><br style=3D"font-family:courier new,monospace"><span style=3D"font-fami=
ly:courier new,monospace">=A0 2530277=A0=A0=A0 1.046=A0=A0=A0 0.000=A0=A0=
=A0 1.843=A0=A0=A0 0.000 string.py:511(replace)</span><br style=3D"font-fam=
ily:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0=A0 228=A0=A0=
=A0 0.843=A0=A0=A0 0.004=A0=A0 31.431=A0=A0=A0 0.138 viewvc.py:1210(get_res=
ult)</span><br style=3D"font-family:courier new,monospace"><span style=3D"f=
ont-family:courier new,monospace">=A0 2530283=A0=A0=A0 0.797=A0=A0=A0 0.000=
=A0=A0=A0 0.797=A0=A0=A0 0.000 {method 'replace' of 'str' o=
bjects}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0 1263164=A0=A0=A0 0.62=
5=A0=A0=A0 0.000=A0=A0=A0 0.625=A0=A0=A0 0.000 {vars}</span><br style=3D"fo=
nt-family:courier new,monospace"><span style=3D"font-family:courier new,mon=
ospace">=A0 1263177=A0=A0=A0 0.591=A0=A0=A0 0.000=A0=A0=A0 0.591=A0=A0=A0 0=
.000 {method 'update' of 'dict' objects}</span><br style=3D=
"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0 631794=A0=A0=A0 0.=
481=A0=A0=A0 0.000=A0=A0=A0 3.552=A0=A0=A0 0.000 viewvc.py:1187(format_text=
)</span><br style=3D"font-family:courier new,monospace"><span style=3D"font=
-family:courier new,monospace">=A0 1268335=A0=A0=A0 0.190=A0=A0=A0 0.000=A0=
=A0=A0 0.190=A0=A0=A0 0.000 {method 'append' of 'list' obje=
cts}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0=A0 600=A0=A0=
=A0 0.142=A0=A0=A0 0.000=A0=A0=A0 0.142=A0=A0=A0 0.000 {method 'split&#=
39; of 'str' objects}</span><br style=3D"font-family:courier new,mo=
nospace"><span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0=A0 =
118=A0=A0=A0 0.079=A0=A0=A0 0.001=A0=A0=A0 0.093=A0=A0=A0 0.001 {_fs.svn_fs=
_check_path}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">637068/636957=A0=A0=A0 0.=
074=A0=A0=A0 0.000=A0=A0=A0 0.074=A0=A0=A0 0.000 {len}</span><br style=3D"f=
ont-family:courier new,monospace"><br>(B) The Directory with one thousand f=
iles<br><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0=A0=A0=A0=A0 =
133750340 function calls (133704141 primitive calls) in 269.160 CPU seconds=
</span><br style=3D"font-family:courier new,monospace"><br style=3D"font-fa=
mily:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0 Ordered by: intern=
al time</span><br style=3D"font-family:courier new,monospace"><span style=
=3D"font-family:courier new,monospace">=A0=A0 List reduced from 1002 to 100=
due to restriction <0.10000000000000001></span><br style=3D"font-fam=
ily:courier new,monospace">
<br style=3D"font-family:courier new,monospace"><span style=3D"font-family:=
courier new,monospace">=A0=A0 ncalls=A0 tottime=A0 percall=A0 cumtime=A0 pe=
rcall filename:lineno(function)</span><br style=3D"font-family:courier new,=
monospace"><span style=3D"font-family:courier new,monospace">=A031701892=A0=
147.583=A0=A0=A0 0.000=A0 147.583=A0=A0=A0 0.000 {built-in method search}<=
/span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0 2087=A0=A0 5=
8.027=A0=A0=A0 0.028=A0 228.247=A0=A0=A0 0.109 viewvc.py:1232(_tokenize_tex=
t)</span><br style=3D"font-family:courier new,monospace"><span style=3D"fon=
t-family:courier new,monospace">=A0 5293057=A0=A0 10.545=A0=A0=A0 0.000=A0=
=A0 25.366=A0=A0=A0 0.000 sapi.py:35(escape)</span><br style=3D"font-family=
:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A010569433=A0=A0=A0 8.86=
8=A0=A0=A0 0.000=A0=A0 19.292=A0=A0=A0 0.000 viewvc.py:4550(__init__)</span=
><br style=3D"font-family:courier new,monospace"><span style=3D"font-family=
:courier new,monospace">=A021174316=A0=A0=A0 8.785=A0=A0=A0 0.000=A0=A0 15.=
433=A0=A0=A0 0.000 string.py:511(replace)</span><br style=3D"font-family:co=
urier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0 2087=A0=A0=
=A0 7.067=A0=A0=A0 0.003=A0 265.489=A0=A0=A0 0.127 viewvc.py:1210(get_resul=
t)</span><br style=3D"font-family:courier new,monospace"><span style=3D"fon=
t-family:courier new,monospace">=A021174322=A0=A0=A0 6.648=A0=A0=A0 0.000=
=A0=A0=A0 6.648=A0=A0=A0 0.000 {method 'replace' of 'str' o=
bjects}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A010569448=A0=A0=A0 5.27=
0=A0=A0=A0 0.000=A0=A0=A0 5.270=A0=A0=A0 0.000 {method 'update' of =
'dict' objects}</span><br style=3D"font-family:courier new,monospac=
e"><span style=3D"font-family:courier new,monospace">=A010569435=A0=A0=A0 5=
.154=A0=A0=A0 0.000=A0=A0=A0 5.154=A0=A0=A0 0.000 {vars}</span><br style=3D=
"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0 5286693=A0=A0=A0 4.23=
8=A0=A0=A0 0.000=A0=A0 30.173=A0=A0=A0 0.000 viewvc.py:1187(format_text)</s=
pan><br style=3D"font-family:courier new,monospace"><span style=3D"font-fam=
ily:courier new,monospace">=A010586140=A0=A0=A0 1.573=A0=A0=A0 0.000=A0=A0=
=A0 1.573=A0=A0=A0 0.000 {method 'append' of 'list' objects=
}</span><br style=3D"font-family:courier new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0 3363=A0=A0=
=A0 1.171=A0=A0=A0 0.000=A0=A0=A0 1.171=A0=A0=A0 0.000 {method 'split&#=
39; of 'str' objects}</span><br style=3D"font-family:courier new,mo=
nospace"><span style=3D"font-family:courier new,monospace">=A0=A0=A0 46995=
=A0=A0=A0 0.761=A0=A0=A0 0.000=A0=A0=A0 0.761=A0=A0=A0 0.000 {method 'w=
rite' of 'file' objects}</span><br style=3D"font-family:courier=
new,monospace">
<span style=3D"font-family:courier new,monospace">=A0=A0=A0=A0 1021=A0=A0=
=A0 0.649=A0=A0=A0 0.001=A0=A0=A0 0.784=A0=A0=A0 0.001 {_fs.svn_fs_check_pa=
th}</span><br style=3D"font-family:courier new,monospace"><span style=3D"fo=
nt-family:courier new,monospace">5298333/5298222=A0=A0=A0 0.611=A0=A0=A0 0.=
000=A0=A0=A0 0.611=A0=A0=A0 0.000 {len}</span><br style=3D"font-family:cour=
ier new,monospace">
<br>Obviously, this situation (large folder, unusually large patch message)=
is an edge case; but the situation should be easy to replicate and the sol=
ution equally straight-forward. <br><br>Two ideas come to mind:<br><br>
(a) pre-truncating the message (e.g. to 10 x the max len intended, to pick =
a heuristic)<br>(b) caching the tokenization summary, since patches usually=
affect multiple files<br><br>Either solution would fix our situation.<br>
<br>Best<br>Robert C. Kahlert<br>Senior Programmer Analyst<br>Cycorp Inc (<=
a href=3D"http://www.cyc.com">http://www.cyc.com</a>)<br>7718 Wood Hollow D=
rive, Suite #250<br>
------=_Part_5452_1008044925.1333134266364--