Re: Reported timing

Sean Tiley <[email protected]> Fri, 18 Dec 2015 10:34:08 -0500
Newsgroups gmane.comp.java.grinder.user
Message-ID <CA+v9W_OyEg-Epfu5Ugjm_4AW302rB1TqryFkBqcequ-X8LtvoA@mail.gmail.com>
--===============1979786256527052676==
Content-Type: multipart/alternative; boundary=001a1149250ec64e5705272dde68

--001a1149250ec64e5705272dde68
Content-Type: text/plain; charset=UTF-8

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

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

<div dir=3D"ltr"><p>Hi Gary,<br>I ran the test once and captured the follow=
ing stats from the console</p><p>200 Page 2 - Login=C2=A0=C2=A0 631<br>201 =
GET start.swe -=C2=A0 338<br>202 GET login.css -=C2=A0 18<br>203 GET swen_t=
p.js - 18<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>209 GET do-not.png - 10<br>210 GET logint.jpg - 29<br>211 GET loginr=
.jpg - 13<br>212 GET transt.gif - 18<br>213 GET favcon.ico - 9</p><p>Adding=
 times for 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 remove=
d).=C2=A0 There are 2 explicit sleeps in the page 2 code for a total of 62,=
 leaving 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;&q=
uot;<br>=C2=A0=C2=A0=C2=A0 result =3D request201.GET(...)<br>=C2=A0=C2=A0=
=C2=A0 request202.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 request2=
07.GET(....)<br>=C2=A0=C2=A0=C2=A0 request208.GET(...)</p><p>=C2=A0=C2=A0=
=C2=A0 grinder.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 gr=
inder.sleep(47)</p><p>=C2=A0=C2=A0=C2=A0 request213.GET(...)<br>=C2=A0=C2=
=A0=C2=A0 return result</p><p>=C2=A0<br>In the __call__<br>I have the follo=
wing</p><p>=C2=A0 def __call__(self):<br>=C2=A0=C2=A0=C2=A0 grinder.getStat=
istics().setDelayReports(True)<br>=C2=A0=C2=A0=C2=A0 &quot;&quot;&quot;Call=
ed for every 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.pag=
e3()=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 the times here are varied slightly automatically from thread to th=
read and not 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<br>Sean</p></div>

--001a1149250ec64e5705272dde68--


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

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

--===============1979786256527052676==
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

--===============1979786256527052676==--