Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

confused by multiple requests in on_start #236

Closed
mblakele opened this issue Jan 27, 2015 · 19 comments · Fixed by #267
Closed

confused by multiple requests in on_start #236

mblakele opened this issue Jan 27, 2015 · 19 comments · Fixed by #267

Comments

@mblakele
Copy link

This is with 0.7.2 from pip, and also using the latest from github. It seems that on_start isn't expecting more than one request, and does strange things when this happens.

Use case: django apps often use a guard token that is the same in headers and form, and posting the form has to replay it correctly: csrfmiddlewaretoken. If a login form uses this token, then the setup phase must GET the form, parse out the token, and then POST the login request with the right token.

class UserBehavior(TaskSet):
    def on_start(self):
        """
        on_start is called when a Locust start before,
        any task is scheduled
        """
        self.login()

    def login(self):
        # Response from GET will include csrfmiddlewaretoken
        resp = self.client.get("/login")
        token = resp.cookies.get('csrftoken')
        self.client.post("/login",
                       {"csrfmiddlewaretoken":token,
                        "username":"joe.test",
                        "password":"test"})

    @task(1)
    def index(self):
        self.client.get("/")

class WebsiteUser(HttpLocust):
    task_set = UserBehavior
    min_wait =  500
    max_wait = 1500

If this locustfile is run with n=1, both login requests are visible in the server log. But locust only reports the GET, not the POST. I think this happens because it is counting requests, and expects the on_start to only contain one request.

If run with n=2, the final summary shows both on_start requests but the server log also shows GET /. With sufficiently large n I suppose this doesn't matter, but it would be more accurate to report on all the requests that were made, whatever value n has.

If the GET / task is removed and n=2, locust goes into a loop of IndexError exceptions.

[2015-01-26 16:34:13,705] localhost/ERROR/stderr: Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/locust/core.py", line 264, in run
    self.schedule_task(self.get_next_task())
  File "/usr/local/lib/python2.7/site-packages/locust/core.py", line 325, in get_next_task
    return random.choice(self.tasks)
  File "/usr/local/Cellar/python/2.7.8_2/Frameworks/Python.framework/Versions/2.7/lib/python2.7/random.py", line 275, in choice
    return seq[int(self.random() * len(seq))]  # raises IndexError if seq is empty
IndexError: list index out of range
[2015-01-26 16:34:15,032] localhost/ERROR/stderr: Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/locust/core.py", line 264, in run
    self.schedule_task(self.get_next_task())
  File "/usr/local/lib/python2.7/site-packages/locust/core.py", line 325, in get_next_task
    return random.choice(self.tasks)
  File "/usr/local/Cellar/python/2.7.8_2/Frameworks/Python.framework/Versions/2.7/lib/python2.7/random.py", line 275, in choice
    return seq[int(self.random() * len(seq))]  # raises IndexError if seq is empty
IndexError: list index out of range
@dantagg
Copy link
Contributor

dantagg commented Mar 25, 2015

I have a similar problem -- testing a drupal app where you have to get the registration form to get the token and hidden form fields and then register with all the extra detail. Again I'm doing it in one task call, but separate session requests. In my case some of the POSTS are getting through, but not all. From info logs my code was producing, I know lots of users were being registered, as I can also see when I look at the admin screen of the website they are there. However as the paste below shows, they are not making it through, either as errors or as successes, lots are being recorded as GETs --
POST register + GET register ~= 2 x logouts

Name                                                          # reqs      # fails     Avg     Min     Max  |  Median   req/s

GET /user/logout                                                 222     0(0.00%)     152      82     454  |     130    4.80
GET /user/register                                               421     0(0.00%)    1202      16    3002  |      43    9.50
POST /user/register                                               21     0(0.00%)    1465    1252    1672  |    1500    0.10

Total                                                            664     0(0.00%)                                      14.40

dantagg added a commit to dantagg/locust that referenced this issue Mar 25, 2015
method was set against the request response method. In the case of a POST request being redirected to GET, common on success of POSTs for login and registration. The request is incorrectly logged against the GET method for the original URL.

Closes locustio#236
@tom-dalton-fanduel
Copy link

I'm seeing a similar issue. In my case, on_start make a single login POST request. The stats in the locust web UI actually show the login request, but it shows it always as 0 requests (0 success, 0 fail, zero avg time etc). I can see the login requests are being made to the server, and the other task requests (done after the on_start has run) are working. So on_start is running the login, and reporting it partially (it appears in the UI), but I get 0 stats for it.

Edit: Actually it appears that the login requests are very occasionally recorded, but at least <= than 1/6 of the time. I am running a master/slave configuration if that makes any difference.

@dantagg
Copy link
Contributor

dantagg commented Mar 27, 2015

Are you getting extra stats for GET requests on the same URL? The problem
is these lines of client.py
https://github.com/locustio/locust/blob/master/locust/clients.py#L107

store meta data that is used when reporting the request to locust's

statistics request_meta = {} # set up pre_request hook for attaching meta
data to the request object request_meta["start_time"] = time.time() response
= self._send_request_safe_mode(method, url, **kwargs) # record the consumed
time request_meta["response_time"] = int((time.time() - request_meta["
start_time"]) * 1000) request_meta["method"] = response.request.method
request_meta["name"] = name or (response.history and response.history[0] or
response).request.path_url
request_meta is a dictionary that gets passed up to the logger. You cans
see that the 'method' value is set against the response, if there has been
any redirects to a GET, then the method is set to a GET, meanwhile the name
is set to 'name' or the url of the first request i.e. the url of the
original POST.

Dan

On 27 March 2015 at 10:50, Tom Dalton [email protected] wrote:

I'm seeing a similar issue. In my case, on_start make a single login POST
request. The stats in the locust web UI actually show the login request,
but it shows it always as 0 requests (0 success, 0 fail, zero avg time
etc). I can see the login requests are being made to the server, and
the other task requests (done after the on_start has run) are working. So
on_start is running the login, and reporting it partially (it appears in
the UI), but I get 0 stats for it.


Reply to this email directly or view it on GitHub
#236 (comment).

Wildman and Herring Limited, Registered Office: 52 Great Eastern Street,
London, EC2A 3EP, Company no: 05766374

@tom-dalton-fanduel
Copy link

None of the requests involved in my tests return or make redirects. Also, I don't (think) I'm getting extra stats, my stats (specifically those from on_start) seem to be missing.

@heyman heyman reopened this Mar 28, 2015
@heyman
Copy link
Member

heyman commented Mar 28, 2015

No idea why this issue was closed, sorry about that.

@tom-dalton-fanduel Do you think your issue could have anything to do with the stats being reset once all Locust instances are spawned? Perhaps you could post a minimal version of your test script that produces this error?

@tom-dalton-fanduel
Copy link

@heyman Ahh that would actually fit the pattern - in the test case I was confused by, I had 30 slaves, with 1 user on each slave. Each user makes a single login in the taskset's on_start and then uses those credentials in all the subsequent tasks. If the stats are reset once the last slave initialises, then that would explain why I only see a few login requests recorded, rather than the 30 I expected. Am I interpreting "all Locust instances are spawned" correctly?

@heyman
Copy link
Member

heyman commented Mar 30, 2015

Yep, once all slave nodes are finished "hatching" their locust instances, the stats gets reset.

If you'd add time.sleep(1.0) at the top of the on_start method, you should probably see all 30 requests, since the hatching_complete event will be fired before the locust instances starts making requests.

@tom-dalton-fanduel
Copy link

Ah I didn't know that. So does that mean if you have a long, slow ramp, then when you hit the top of the ramp the stats will be reset? Is there any way to prevent that, so the stats show both the hatching/ramp phase and the subsequent "steady-state"/"table-top" phase?

@heyman
Copy link
Member

heyman commented Mar 30, 2015

At the moment there is no clean way of doing this. The reason the stats are cleared is because the requests made during the hatching phase is usually not representative for the number of users you want to simulate, and there might also be caches that aren't warmed up etc.

However it should probably be configurable as it has been requested before, and I can see that there might be cases where you wouldn't want to reset the stats.

If you add the following somewhere at the module level of your test scripts you'll monkey patch Locust to not reset any stats ever (will also make the "Reset stats" button in the web UI not work):

from locust.stats import RequestStats
def noop(*arg, **kwargs):
    print "Stats reset prevented by monkey patch!"
RequestStats.reset_all = noop

@tom-dalton-fanduel
Copy link

That's fine, thanks.

@heyman heyman closed this as completed Mar 30, 2015
@DataGreed
Copy link

Well, why was this closed?

on_start is a very important part of load tests and was one of the main reasons I've chosen locust for load testing. In my case there are 6 requests (i may have a very specific use-case, though, i am testing API for a realtime mobile application, so there is registering new user, logging in, uploading photo, activating paid subscription, etc...

BTW, any exceptions generated in on_start method are not shown in web panel, though it's not that important, but method statistics are essential.

P.S. Keep up the good work, there is really no good alternative for locust, yet.

@heyman
Copy link
Member

heyman commented Apr 7, 2015

@DataGreed This issue was closed because the problem didn't have anything to do with on_start. Instead the problems discussed in this issue are covered in other issues:

#267 - Fixed and merged
#205 - Open issue
#269 - Opened by you, thanks for the report

If there is some other issue that I've missed please tell me, and feel free to re-open :)

@DataGreed
Copy link

@heyman thanks! That was not obvious from the comments :)

@phoebebright
Copy link

I've just installed locust 0.7.3 on osx to test a django site and used the a virtually identical piece of code to the original poster and run straight into the list index out of range error. I'm probably being dense but its not clear to me from the comments above whether the issue is fixed or whether I need to change my code?

I'm just running 1 user with the default call locust --host=http://localhost:8000

@dantagg
Copy link
Contributor

dantagg commented Dec 10, 2015

I don't know either. Can you post the actual code that is causing the
problem?

Dan

On 9 December 2015 at 21:17, Phoebe Bright [email protected] wrote:

I've just installed locust 0.7.3 on osx to test a django site and used the
a virtually identical piece of code to the original poster and run straight
into the list index out of range error. I'm probably being dense but its
not clear to me from the comments above whether the issue is fixed or
whether I need to change my code?

I'm just running 1 user with the default call locust --host=
http://localhost:8000


Reply to this email directly or view it on GitHub
#236 (comment).

Wildman and Herring Limited, Registered Office: 52 Great Eastern Street,
London, EC2A 3EP, Company no: 05766374

@phoebebright
Copy link

Here is the locustfile.py

from locust import HttpLocust, TaskSet

class UserBehavior(TaskSet):
    def on_start(self):
        self.login()

    def login(self):
        response = self.client.get("/login/")
        csrftoken = response.cookies['csrftoken']
        response = self.client.post("/login/",
                                {"username": "test",
                                 "password": "test"},
                                headers={"X-CSRFToken": csrftoken})


class WebsiteUser(HttpLocust):
    host = 'http://localhost:8000'
    task_set = UserBehavior

and the error - repeated many times:

[2015-12-09 21:08:18,936] iMacs-iMac.local/ERROR/stderr: Traceback (most recent call last):
  File "/Users/phoebebr/.virtualenvs/board/lib/python2.7/site-packages/locust/core.py", line 264, in run
    self.schedule_task(self.get_next_task())
  File "/Users/phoebebr/.virtualenvs/board/lib/python2.7/site-packages/locust/core.py", line 325, in get_next_task
    return random.choice(self.tasks)
  File "/usr/local/Cellar/python/2.7.8_2/Frameworks/Python.framework/Versions/2.7/lib/python2.7/random.py", line 275, in choice
    return seq[int(self.random() * len(seq))]  # raises IndexError if seq is empty
IndexError: list index out of range

@cjsimpson
Copy link

I think you need to put "@task" above the login function.

@dantagg
Copy link
Contributor

dantagg commented Dec 10, 2015

Hi,

cjsimpson said "I think you need to put "@task https://github.com/task"
above the login function." I don't think that is quite right. but within
the UserBehavior class, you do need something which has been decorated as a
task to run. In the example at the top of this thread it was

@task(1)
def index(self):
    self.client.get("/")

Dan

On 10 December 2015 at 09:43, Phoebe Bright [email protected]
wrote:

Here is the locustfile.py

from locust import HttpLocust, TaskSet

class UserBehavior(TaskSet):
def on_start(self):
self.login()

def login(self):
    response = self.client.get("/login/")
    csrftoken = response.cookies['csrftoken']
    response = self.client.post("/login/",
                            {"username": "test",
                             "password": "test"},
                            headers={"X-CSRFToken": csrftoken})

class WebsiteUser(HttpLocust):
host = 'http://localhost:8000'
task_set = UserBehavior

and the error - repeated many times:

[2015-12-09 21:08:18,936] iMacs-iMac.local/ERROR/stderr: Traceback (most recent call last):
File "/Users/phoebebr/.virtualenvs/board/lib/python2.7/site-packages/locust/core.py", line 264, in run
self.schedule_task(self.get_next_task())
File "/Users/phoebebr/.virtualenvs/board/lib/python2.7/site-packages/locust/core.py", line 325, in get_next_task
return random.choice(self.tasks)
File "/usr/local/Cellar/python/2.7.8_2/Frameworks/Python.framework/Versions/2.7/lib/python2.7/random.py", line 275, in choice
return seq[int(self.random() * len(seq))] # raises IndexError if seq is empty
IndexError: list index out of range


Reply to this email directly or view it on GitHub
#236 (comment).

Wildman and Herring Limited, Registered Office: 52 Great Eastern Street,
London, EC2A 3EP, Company no: 05766374

@phoebebright
Copy link

Yes, adding the task decorator fixes the out of range error. Full code for reference is:

from locust import HttpLocust, TaskSet, task

class UserBehavior(TaskSet):
    def on_start(self):
        self.login()

    @task(1)
    def login(self):
        response = self.client.get("/login/")
        csrftoken = response.cookies['csrftoken']
        response = self.client.post("/login/",
                                    {"username": "test",
                                     "password": "fuschia"},
                                    headers={"X-CSRFToken": csrftoken})


class WebsiteUser(HttpLocust):
    host = 'http://localhost:8000'
    task_set = UserBehavior

Thanks for your help.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
7 participants