Re: Reported timing

Marc Holden <[email protected]> Fri, 18 Dec 2015 16:20:33 +0000
Newsgroups gmane.comp.java.grinder.user
Message-ID <CADV_OVVhoAXEeERhdeQLJDNLnr68H_=aVcdZL+GtH7zGP5de8g@mail.gmail.com>
--===============8324916554135341024==
Content-Type: multipart/alternative; boundary=089e013a254860916a05272e851d

--089e013a254860916a05272e851d
Content-Type: text/plain; charset=UTF-8

Hi Sean,

Have you tried to ignoring the few sample sets that come in and allow the
test to run for a few minutes.  There may be class
loading/caching/instrumentation/networking latency you are experiencing.

-Marc

On Fri, Dec 18, 2015 at 10:37 AM Sean Tiley <[email protected]> wrote:

> Hi Gary,
> I ran the test once and captured the following stats from the console
>
> 200 Page 2 - Login   631
> 201 GET start.swe -  338
> 202 GET login.css -  18
> 203 GET swen_tp.js - 18
> 204 GET log7_d.gif - 19
> 205 GET login.js -   7
> 206 GET swecmhi.js - 20
> 207 GET swi_top.js - 23
> 208 GET swecoon.js - 17
> 209 GET do-not.png - 10
> 210 GET logint.jpg - 29
> 211 GET loginr.jpg - 13
> 212 GET transt.gif - 18
> 213 GET favcon.ico - 9
>
> Adding times for 201-213 gives 539.  That leaves a difference of 92.
>
>
> my page 2 function looks like this, (unnecessary bits removed).  There are
> 2 explicit sleeps in the page 2 code for a total of 62, leaving 30
> unaccounted for.
>
>
>   def page2(self):
>     """GET start.swe (requests 201-213)."""
>     result = request201.GET(...)
>     request202.GET(...)
>     request203.GET(...)
>     request204.GET(...)
>     request205.GET(...)
>     request206.GET(...)
>     request207.GET(....)
>     request208.GET(...)
>
>     grinder.sleep(15)
>
>     request209.GET(...)
>     request210.GET(...)
>     request211.GET(...)
>     request212.GET(...)
>
>     grinder.sleep(47)
>
>     request213.GET(...)
>     return result
>
>
> In the __call__
> I have the following
>
>   def __call__(self):
>     grinder.getStatistics().setDelayReports(True)
>     """Called for every run performed by the worker thread."""
>     self.page1()      # GET / (request 101)
>
>     grinder.sleep(47)
>     self.page2()      # GET start.swe (requests 201-213)
>
>     grinder.sleep(10188)
>     self.page3()      # POST start.swe (request 301)
>
> ......snip
>
>
> There is an explicit sleep of 47 between page 1 and 2 but I think the
> times here are varied slightly automatically from thread to thread and not
> counted in the reported times?
>
> So not really sure where the addidional time comes from?
>
> Any thoughts are welcomed
>
> Thanks
>
>
> Sean
>
> ------------------------------------------------------------------------------
> _______________________________________________
> grinder-use mailing list
> [email protected]
> https://lists.sourceforge.net/lists/listinfo/grinder-use
>

--089e013a254860916a05272e851d
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Hi Sean,<div><br></div><div>Have you tried to ignoring the=
 few sample sets that come in and allow the test to run for a few minutes.=
=C2=A0 There may be class loading/caching/instrumentation/networking latenc=
y you are experiencing.=C2=A0</div><div><br></div><div>-Marc =C2=A0</div></=
div><br><div class=3D"gmail_quote"><div dir=3D"ltr">On Fri, Dec 18, 2015 at=
 10:37 AM Sean Tiley &lt;<a href=3D"mailto:[email protected]">sean.tiley=
@gmail.com</a>&gt; wrote:<br></div><blockquote class=3D"gmail_quote" style=
=3D"margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir=
=3D"ltr"><p>Hi Gary,<br>I ran the test once and captured the following stat=
s from the console</p><p>200 Page 2 - Login=C2=A0=C2=A0 631<br>201 GET star=
t.swe -=C2=A0 338<br>202 GET login.css -=C2=A0 18<br>203 GET swen_tp.js - 1=
8<br>204 GET log7_d.gif - 19<br>205 GET login.js -=C2=A0=C2=A0 7<br>206 GET=
 swecmhi.js - 20<br>207 GET swi_top.js - 23<br>208 GET swecoon.js - 17<br>2=
09 GET do-not.png - 10<br>210 GET logint.jpg - 29<br>211 GET loginr.jpg - 1=
3<br>212 GET transt.gif - 18<br>213 GET favcon.ico - 9</p><p>Adding times f=
or 201-213 gives=C2=A0539.=C2=A0 That leaves a difference of 92.</p><p><br>=
</p><p>my page 2 function looks like this, (unnecessary bits removed).=C2=
=A0 There are 2 explicit sleeps in the page 2 code for a total of 62, leavi=
ng 30 unaccounted for.</p><p><br>=C2=A0 def page2(self):<br>=C2=A0=C2=A0=C2=
=A0 &quot;&quot;&quot;GET start.swe (requests 201-213).&quot;&quot;&quot;<b=
r>=C2=A0=C2=A0=C2=A0 result =3D request201.GET(...)<br>=C2=A0=C2=A0=C2=A0 r=
equest202.GET(...)<br>=C2=A0=C2=A0=C2=A0 request203.GET(...)<br>=C2=A0=C2=
=A0=C2=A0 request204.GET(...)<br>=C2=A0=C2=A0=C2=A0 request205.GET(...)<br>=
=C2=A0=C2=A0=C2=A0 request206.GET(...)<br>=C2=A0=C2=A0=C2=A0 request207.GET=
(....)<br>=C2=A0=C2=A0=C2=A0 request208.GET(...)</p><p>=C2=A0=C2=A0=C2=A0 g=
rinder.sleep(15)</p><p>=C2=A0=C2=A0=C2=A0 request209.GET(...)<br>=C2=A0=C2=
=A0=C2=A0 request210.GET(...)<br>=C2=A0=C2=A0=C2=A0 request211.GET(...)<br>=
=C2=A0=C2=A0=C2=A0 request212.GET(...)</p><p>=C2=A0=C2=A0=C2=A0 grinder.sle=
ep(47)</p><p>=C2=A0=C2=A0=C2=A0 request213.GET(...)<br>=C2=A0=C2=A0=C2=A0 r=
eturn result</p><p>=C2=A0<br>In the __call__<br>I have the following</p><p>=
=C2=A0 def __call__(self):<br>=C2=A0=C2=A0=C2=A0 grinder.getStatistics().se=
tDelayReports(True)<br>=C2=A0=C2=A0=C2=A0 &quot;&quot;&quot;Called for ever=
y run performed by the worker thread.&quot;&quot;&quot;<br>=C2=A0=C2=A0=C2=
=A0 self.page1()=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 # GET / (request 101)</p><p>=
=C2=A0=C2=A0=C2=A0 grinder.sleep(47)<br>=C2=A0=C2=A0=C2=A0 self.page2()=C2=
=A0=C2=A0=C2=A0=C2=A0=C2=A0 # GET start.swe (requests 201-213)</p><p>=C2=A0=
=C2=A0=C2=A0 grinder.sleep(10188)<br>=C2=A0=C2=A0=C2=A0 self.page3()=C2=A0=
=C2=A0=C2=A0=C2=A0=C2=A0 # POST start.swe (request 301)</p><p>......snip</p=
><p><br>There is an explicit sleep of 47 between page 1 and 2 but I think t=
he times here are varied slightly automatically from thread to thread and n=
ot counted in the reported times?=C2=A0</p><p>So not really sure where the =
addidional time comes from?</p><p>Any thoughts are welcomed</p><p>Thanks</p=
></div><div dir=3D"ltr"><p><br>Sean</p></div>
---------------------------------------------------------------------------=
---<br>
_______________________________________________<br>
grinder-use mailing list<br>
<a href=3D"mailto:[email protected]" target=3D"_blank">grin=
[email protected]</a><br>
<a href=3D"https://lists.sourceforge.net/lists/listinfo/grinder-use" rel=3D=
"noreferrer" target=3D"_blank">https://lists.sourceforge.net/lists/listinfo=
/grinder-use</a><br>
</blockquote></div>

--089e013a254860916a05272e851d--


--===============8324916554135341024==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

------------------------------------------------------------------------------

--===============8324916554135341024==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
grinder-use mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/grinder-use

--===============8324916554135341024==--