Why does locust not send requests after a while? How can I solve it?

Question

I was trying to test the performance. But I noticed that no new request was made after a while, only the temporary result reports are printed at intervals, the number of requests freezes until locust stopped when reaching the time limit.

Part of logs:

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

 Name                                                          # reqs      # fails  |     Avg     Min     Max  Median  |   req/s failures/s
--------------------------------------------------------------------------------------------------------------------------------------------
 POST /eaog/CreateSess                                            691     0(0.00%)  |     790     250    4406     590  |   13.20    0.00
 POST /eaog/ReceiveInsRsp                                         691     0(0.00%)  |     557       0    2843     390  |   12.90    0.00
--------------------------------------------------------------------------------------------------------------------------------------------
 Aggregated                                                      1382     0(0.00%)  |     674       0    4406     520  |   26.10    0.00

[2020-10-09 20:35:13,127] DESKTOP-AF8SR9S/INFO/locust.main: Time limit reached. Stopping Locust.
[2020-10-09 20:35:13,127] DESKTOP-AF8SR9S/INFO/locust.runners: Stopping 20 users

Here is part of the code: class TaskbotTaskSet(TaskSet):

def on_start(self):
    get_flow_id()

def on_stop(self):
    print("body_count: {}; response_count: {}".format(body_count, response_count))

@task
def create_sess(self):
    sid = str(uuid.uuid1())
    body = {"taskId": {
        "bid": bid,
        "sid": sid},
        "appId": "BCCS"}
    body = json.dumps(body).encode('utf-8')

    global body_count
    body_count += 1

    print("post create_sess body: {}".format(body))
    with self.client.post(api_url['CreateSess'], data=body, headers=headers, catch_response=True) as res:
        global response_count
        response_count += 1

        print(res.text)
        if res.status_code != 200:
            res.failure('request failed: %s ' % res.text)
        else:
            msg = json.loads(res.text)
            if msg['code'] == 0:
                q.put(sid)
                res.success()
            else:
                res.failure('request returned with error: %s ' % res.text)

@task
def receive_rsp(self):
    sid = q.get()
    flow_id = random.choice(flow_ls)
    body = {
        "taskId": {
            "bid": bid,
            "sid": sid,
            "flow_id": flow_id,
            "ins_id": "t-1",
            "res": "test_result"},
        "appId": "BCCS"
    }
    body = json.dumps(body).encode('utf-8')

    global body_count
    body_count += 1

    print("post receive body: {}".format(body))
    with self.client.post(api_url['ReceiveInsRsp'], data=body, headers=headers, catch_response=True) as res:
        global response_count
        response_count += 1
        q2delete.put(sid)
        print(res.text)
        if res.status_code != 200:
            res.failure('request failed: %s' % res.text)
        else:
            msg = json.loads(res.text)
            if msg['code'] == 0:
                res.success()
            else:
                res.failure('request returned with error: %s' % res.text)

Environment:

The version of python: Python 3.7.6 (default, Jan 8 2020, 20:23:39) [MSC v.1916 64 bit (AMD64)] :: Anaconda, Inc. on win32
The version of locust: locust 1.2.3
Hardware: intel core i7-8700 @3.2GHz, memory: 16GB

Any help is appreciated

If you repeat the test, does it get to roughly the same point every time before stopping? Are there any log lines that might be relevant that might point to what’s happening or where it is in the code when it stops? You could add some, if not. What’s the command you’re using to run Locust? — Solowalker, Oct 09 '20 at 14:13
Every time I repeat the test, the number of requests is different when it freezes. I did put the log lines before sending requests and after receiving responses, and try to count them. I found that the body_count is 10 more than the response_count if it not freezes when I set the number of client as 10, but they get same if it freezes. — Yiling, Oct 10 '20 at 01:34
The command line I used: locust -f locust_taskbot.py --host=[HOST] --headless -u 10 -r 10 -t 5min — Yiling, Oct 10 '20 at 01:35
Does it work for longer if you do fewer users? Can you also try using a single request body and whatnot to simplify things and make sure there’s not anything else in your code that might be causing problems? Also, does your system you’re testing work if you try to only get responses? Maybe try making this a SequentialTaskSet to make sure the request is sent first before the response. — Solowalker, Oct 10 '20 at 22:33

score 0 · Answer 1 · answered Oct 09 '20 at 17:03

0

Not sure about the server/api you are testing, but is it possible that self.client.post(api_url['ReceiveInsRsp']...) will wait until there is something to receive? You can override the request timeout (check requests documentation) to force an error, to check if this is the case.

answered Oct 09 '20 at 17:03

Cyberwiz

11,027
3
20
40

I try to set the timeout as 20, but no exception was caught when it freezes. It really confuses me. – Yiling Oct 10 '20 at 03:28
I also wrote a script using ThreadPoolExecutor, I also used Requests, but it works fine – Yiling Oct 10 '20 at 03:31
What is the variable q in your test? Is it possible that q.get() is blocking? – Cyberwiz Oct 10 '20 at 07:03
The variable q is the queue to record the sid, it is added in the queue when requesting api_url['CreateSess'], and pops out when requesting api_url['ReceiveRsp']. I changed the script to inherit the SequentialTaskSet to make sure q.push() before q.get(), but it also failed, still frozen after a while. – Yiling Oct 10 '20 at 09:00
Try adding some print statements in your task to see if you can narrow down exactly where it gets stuck (start with before and after the post) – Cyberwiz Oct 10 '20 at 12:28

score 0 · Answer 2 · answered Oct 13 '20 at 09:02

I have to admit that I am not familiar with Python... These days, I even read the source code of Locust trying to figure it out. Finally, I found that when using Queue to store data, the program gets stuck with Queue.get() if no data in it at all, and no exception will be raised. So please be careful when using Queue, it might get you trouble.

Why does locust not send requests after a while? How can I solve it?

2 Answers2