Re: [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:39:30 -0500
Newsgroups gmane.comp.version-control.cvs.viewcvs.devel
Message-ID <CAGgsKjzx==Sq-rV1_2WX460i3RSEmn1HfSeeQF7CqeDJAdr5sg@mail.gmail.com>
------=_Part_5475_1667490479.1333136395358
Content-Type: multipart/alternative; 
	boundary="----=_Part_5476_850887203.1333136395359"

------=_Part_5476_850887203.1333136395359
Content-Type: text/plain; charset=us-ascii
Content-Transfer-Encoding: 7bit

Thanks for the rapid response!

Let me start at the bottom--I have attached my testing script, anonymized
to take out some of the locale specific information.

Basically, I fake a CGI environment (cribbed from the Apache settings by a
print-environment script like the one mentioned here
http://python.about.com/od/cgiformswithpython/ss/test_cgi.htm) and then
invoke viewvc.py via the profiler.

Took a while to get setup but so worth it.

More interspersed below.
Best
--rck

On Fri, Mar 30, 2012 at 2:27 PM, C. Michael Pilato <[email protected]>wrote:

> On 03/30/2012 03:00 PM, Robert C. Kahlert wrote:
> > Hi,
> >
> > this may or may not be the right list to report this problem to, so
> > apologies if it is not.
>
> You've hit the right list!
>

Great!


>
> > 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.
>
> [...]
>
> > 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.
>
> The pre-truncation approach would (obviously) be easier to implement.
>
> Caching the tokenization results is a pretty good idea, too, but obviously
> more complicated.  What to use as the cache key?  For Subversion, you could
> use the revision number.  Not so for CVS.  So ... perhaps a SHA1 checksum
> of
> the log message?
>

In our particular case, just caching the tokenization for the same patch
message of the same directory list run would have helped. A more general
caching scheme is harder of course, as you said.  So I would be lazy and
initially just cache the output of get_result on the tuple of s and maxlen.


>
> Of course, even if the same log message *doesn't* appear on multiple files,
> I realize now that ViewVC will still process the log message twice per file
> -- once without the maxlen set, once with.  Since no caller ever wants
> *only* the truncated log message, it seems that at a minimum I could make
> format_log() return a 2-tuple containing the full log message and the
> shortened form (and sometimes they'd be exactly the same string).  If more
> advanced caching was added, it could be added around the results of
> format_log().
>

Ditto, and that could be cached.


>
> -- C-Mike
>
> PS:  How did you perform your profiling?  That's a trick I've only done
> with
> C programs ... haven't played with it in Python yet.
>

See attached file and explanations above.


>
> --
> C. Michael Pilato <[email protected]>
> CollabNet   <>   www.collab.net   <>   Distributed Development On Demand
>
>

------------------------------------------------------
http://viewvc.tigris.org/ds/viewMessage.do?dsForumId=4251&dsMessageId=2942590

To unsubscribe from this discussion, e-mail: [[email protected]].
------=_Part_5476_850887203.1333136395359
Content-Type: text/html; charset=ISO-8859-1
Content-Transfer-Encoding: quoted-printable

Thanks for the rapid response! <br><br>Let me start at the bottom--I have a=
ttached my testing script, anonymized to take out some of the locale specif=
ic information. <br><br>Basically, I fake a CGI environment (cribbed from t=
he Apache settings by a print-environment script like the one mentioned her=
e <a href=3D"http://python.about.com/od/cgiformswithpython/ss/test_cgi.htm"=
>http://python.about.com/od/cgiformswithpython/ss/test_cgi.htm</a>) and the=
n invoke viewvc.py via the profiler.<br>

<br>Took a while to get setup but so worth it.<br><br>More interspersed bel=
ow.<br>Best<br>--rck<br><br><div class=3D"gmail_quote">On Fri, Mar 30, 2012=
 at 2:27 PM, C. Michael Pilato <span dir=3D"ltr">&lt;<a href=3D"mailto:cmpi=
[email protected]">[email protected]</a>&gt;</span> wrote:<br>

<blockquote class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;border-left:1p=
x #ccc solid;padding-left:1ex"><div class=3D"im">On 03/30/2012 03:00 PM, Ro=
bert C. Kahlert wrote:<br>
&gt; Hi,<br>
&gt;<br>
&gt; this may or may not be the right list to report this problem to, so<br=
>
&gt; apologies if it is not.<br>
<br>
</div>You&#39;ve hit the right list!<br></blockquote><div><br>Great!<br>=A0=
</div><blockquote class=3D"gmail_quote" style=3D"margin:0pt 0pt 0pt 0.8ex;b=
order-left:1px solid rgb(204,204,204);padding-left:1ex">
<div class=3D"im"><br>
&gt; We are running into a situation with ViewVC 1.1.13 where the get_resul=
t()<br>
&gt; method in viewvc.py (line 1210) is being bitten by an update with a ve=
ry<br>
&gt; long VC log message (~250K).<br>
&gt;<br>
&gt; Specifically, the maxlen parameter does not seem to be passed down to =
the<br>
&gt; self._tokenize_text() method, which is going to town on the 250K messa=
ge,<br>
&gt; calling the search method millions of times, for emitting a few hundre=
d<br>
&gt; characters in the summary view.<br>
<br>
</div>[...]<br>
<div class=3D"im"><br>
&gt; Two ideas come to mind:<br>
&gt;<br>
&gt; (a) pre-truncating the message (e.g. to 10 x the max len intended, to =
pick a<br>
&gt; heuristic)<br>
&gt; (b) caching the tokenization summary, since patches usually affect mul=
tiple<br>
&gt; files<br>
&gt;<br>
&gt; Either solution would fix our situation.<br>
<br>
</div>The pre-truncation approach would (obviously) be easier to implement.=
<br>
<br>
Caching the tokenization results is a pretty good idea, too, but obviously<=
br>
more complicated. =A0What to use as the cache key? =A0For Subversion, you c=
ould<br>
use the revision number. =A0Not so for CVS. =A0So ... perhaps a SHA1 checks=
um of<br>
the log message?<br></blockquote><div><br>In our particular case, just cach=
ing the tokenization for the same patch message of the same directory list =
run would have helped. A more general caching scheme is harder of course, a=
s you said.=A0 So I would be lazy and initially just cache the output of ge=
t_result on the tuple of s and maxlen.<br>

=A0</div><blockquote class=3D"gmail_quote" style=3D"margin:0pt 0pt 0pt 0.8e=
x;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
Of course, even if the same log message *doesn&#39;t* appear on multiple fi=
les,<br>
I realize now that ViewVC will still process the log message twice per file=
<br>
-- once without the maxlen set, once with. =A0Since no caller ever wants<br=
>
*only* the truncated log message, it seems that at a minimum I could make<b=
r>
format_log() return a 2-tuple containing the full log message and the<br>
shortened form (and sometimes they&#39;d be exactly the same string). =A0If=
 more<br>
advanced caching was added, it could be added around the results of<br>
format_log().<br></blockquote><div><br>Ditto, and that could be cached. <br=
>=A0</div><blockquote class=3D"gmail_quote" style=3D"margin:0pt 0pt 0pt 0.8=
ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br>
-- C-Mike<br>
<br>
PS: =A0How did you perform your profiling? =A0That&#39;s a trick I&#39;ve o=
nly done with<br>
C programs ... haven&#39;t played with it in Python yet.<br></blockquote><d=
iv><br>See attached file and explanations above.<br>=A0</div><blockquote cl=
ass=3D"gmail_quote" style=3D"margin:0pt 0pt 0pt 0.8ex;border-left:1px solid=
 rgb(204,204,204);padding-left:1ex">


<span class=3D"HOEnZb"><font color=3D"#888888"><br>
--<br>
C. Michael Pilato &lt;<a href=3D"mailto:[email protected]">cmpilato@colla=
b.net</a>&gt;<br>
CollabNet =A0 &lt;&gt; =A0 <a href=3D"http://www.collab.net" target=3D"_bla=
nk">www.collab.net</a> =A0 &lt;&gt; =A0 Distributed Development On Demand<b=
r>
<br>
</font></span></blockquote></div><br>

------=_Part_5476_850887203.1333136395359--

------=_Part_5475_1667490479.1333136395358
Content-Type: application/x-sh; name=anon-test-viewvc.sh
Content-Transfer-Encoding: base64
X-Attachment-Id: f_h0fmr9ej1
Content-Disposition: attachment; filename=anon-test-viewvc.sh

IyEvYmluL2Jhc2gKIwojIFRlc3QgdGhlIFZpZXdWQyBzY3JpcHQgb24gQ29sb3NzdXMKIwojCiMK
IyBVc2FnZTogYW5vbi10ZXN0LXZpZXd2Yy5zaCBQQVRIIFRBRwojCiMgRXhhbXBsZToKIwojICAg
Li9hbm9uLXRlc3Qtdmlld3ZjLnNoIC90cnVuay9wYXRoL3RvL2ZpbGUgc21hbGwtZmlsZQojCiMK
IyAtLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tCiMgKGEpIFNldHVw
IHRoZSBFbnZpcm9ubWVudAojIC0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0t
LS0tLS0KCkZJTEVQQVRIPSIkMSIKRVhURU5TSU9OPSItJDIiCgpleHBvcnQgRE9DVU1FTlRfUk9P
VD0nL3NyYy9zdm4nCmV4cG9ydCBHQVRFV0FZX0lOVEVSRkFDRT0nQ0dJLzEuMScKZXhwb3J0IEhU
VFBfQUNDRVBUPSd0ZXh0L2h0bWwsYXBwbGljYXRpb24veGh0bWwreG1sLGFwcGxpY2F0aW9uL3ht
bDtxPTAuOSwqLyo7cT0wLjgnCmV4cG9ydCBIVFRQX0FDQ0VQVF9FTkNPRElORz0nZ3ppcCwgZGVm
bGF0ZScKZXhwb3J0IEhUVFBfQUNDRVBUX0xBTkdVQUdFPSdlbi11cyxlbjtxPTAuNScKZXhwb3J0
IEhUVFBfQ0FDSEVfQ09OVFJPTD0nbWF4LWFnZT0wJwpleHBvcnQgSFRUUF9DT05ORUNUSU9OPSdr
ZWVwLWFsaXZlJwpleHBvcnQgSFRUUF9DT09LSUU9J19fdXRtYT0yNTkzNTA1NTIuMTIzODA1MjE3
MS4xMTYxMjc2MTQ5LjEyNTgwNDQ1OTcuMTI3MjkxNzE0MS4zOScKZXhwb3J0IEhUVFBfSE9TVD0n
c3ZuLmhvc3QuY29tJwpleHBvcnQgSFRUUF9VU0VSX0FHRU5UPSdNb3ppbGxhLzUuMCAoWDExOyBM
aW51eCBpNjg2IG9uIHg4Nl82NDsgcnY6MTEuMCkgR2Vja28vMjAxMDAxMDEgRmlyZWZveC8xMS4w
JwpleHBvcnQgUEFUSD0nL3NiaW46L3Vzci9zYmluOi9iaW46L3Vzci9iaW4nCmV4cG9ydCBQQVRI
X0lORk89JHtGSUxFUEFUSH0KZXhwb3J0IFBBVEhfVFJBTlNMQVRFRD0iL3NyYy9zdm4ke0ZJTEVQ
QVRIfSIKZXhwb3J0IFFVRVJZX1NUUklORz0nJwpleHBvcnQgUkVNT1RFX0FERFI9JzEwLjEuMS4x
NDMnCmV4cG9ydCBSRU1PVEVfUE9SVD0nNDc1NjUnCmV4cG9ydCBSRVFVRVNUX01FVEhPRD0nR0VU
JwpleHBvcnQgUkVRVUVTVF9VUkk9Ii9jZ2ktYmluL3ZpZXd2Yy5jZ2kke0ZJTEVQQVRIfSIKZXhw
b3J0IFNDUklQVF9GSUxFTkFNRT0nL3Zhci93d3cvY2dpLWJpbi92aWV3dmMuY2dpJwpleHBvcnQg
U0NSSVBUX05BTUU9Jy9jZ2ktYmluL3ZpZXd2Yy5jZ2knCmV4cG9ydCBTRVJWRVJfQUREUj0nMTAu
MS4xLjE0NCcKZXhwb3J0IFNFUlZFUl9BRE1JTj0nWU9VUkFETUlOSEVSRScKZXhwb3J0IFNFUlZF
Ul9OQU1FPSdzdm4uaG9zdC5jb20nCmV4cG9ydCBTRVJWRVJfUE9SVD0nODAnCmV4cG9ydCBTRVJW
RVJfUFJPVE9DT0w9J0hUVFAvMS4xJwpleHBvcnQgU0VSVkVSX1NJR05BVFVSRT0nPGFkZHJlc3M+
QXBhY2hlLzIuMi4xNSAoQ2VudE9TKSBTZXJ2ZXIgYXQgc3ZuLmhvc3QuY29tIFBvcnQgODA8L2Fk
ZHJlc3M+JwpleHBvcnQgU0VSVkVSX1NPRlRXQVJFPSdBcGFjaGUvMi4yLjE1IChDZW50T1MpJwoK
IyAtLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0KIyAoYikgSW52
b2tlIFZpZXdWQwojIC0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0tLS0t
LQovdXNyL2Jpbi9weXRob24gLW0gY1Byb2ZpbGUgLW8gL3RtcC92aWV3dmMtY2dpLXRyYWNlIC92
YXIvd3d3L2NnaS1iaW4vdmlld3ZjLmNnaQovdXNyL2Jpbi9weXRob24gLWMgImltcG9ydCBwc3Rh
dHM7IHBzdGF0cy5TdGF0cygnL3RtcC92aWV3dmMtY2dpLXRyYWNlJykuc3RyaXBfZGlycygpLnNv
cnRfc3RhdHMoJ3RpbWUnKS5wcmludF9zdGF0cyguMSkiIHwgdGVlIC90bXAvdmlld3ZjLWNnaS10
cmFjZS1saXN0JHtFWFRFTlNJT059CmxzIC10bCAvdG1wL3ZpZXd2Yy1jZ2ktdHJhY2UqCg==
------=_Part_5475_1667490479.1333136395358--