search

SvenskaSpel / locust-plugins

A set of useful plugins/extensions for Locust
Apache License 2.0
557 stars 138 forks source link

Use `-i` arg to test isn't get exact test result when using `TaskSet` and distributed mode #134

Closed YeungHoiChiu closed 4 months ago

YeungHoiChiu commented 1 year ago 
# master command line
locust -f tmp_test_case/live.py -u 10 -r 10 --master --expect-workers 2 --headless --only-summary -i 40 -s 60
# worker
locust -f tmp_test_case/live.py --worker --logfile tmp_test_case/live.log

The master log

[2023-08-01 14:55:21,276] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Starting Locust 2.15.1
[2023-08-01 14:55:21,276] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 2 ready workers
[2023-08-01 14:55:21,325] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: All users spawned: {"Run": 10} (10 total users)
[2023-08-01 14:55:27,645] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 1 ready workers
[2023-08-01 14:55:28,647] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users)
[2023-08-01 14:55:28,647] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker 'HUAWEI-MateBook-X-Pro.local_d5eeb52d2d724026bab1ae2a5d2bbca2' (index 0) quit. 0 workers ready.
[2023-08-01 14:55:28,647] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker 'HUAWEI-MateBook-X-Pro.local_0839937ef61341babdc2991005e92472' (index 1) quit. 0 workers ready.
[2023-08-01 14:55:28,647] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: The last worker quit, stopping test.
[2023-08-01 14:55:29,651] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Shutting down (exit code 0)
Type     Name                                                                          # reqs      # fails |    Avg     Min     Max    Med |   req/s  failures/s
--------|----------------------------------------------------------------------------|-------|-------------|-------|-------|-------|-------|--------|-----------
GET      None-/api/ecwechat/wechat/polymerize/homePage/v1?page=1&sourceType=1&tarId=-1&cursor=      77     0(0.00%) |    359     260     643    320 |   12.95        0.00
--------|----------------------------------------------------------------------------|-------|-------------|-------|-------|-------|-------|--------|-----------
         Aggregated                                                                        77     0(0.00%) |    359     260     643    320 |   12.95        0.00

The worker log

[2023-08-01 12:22:09,553] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Starting Locust 2.15.1
[2023-08-01 12:22:16,506] HUAWEI-MateBook-X-Pro.local/INFO/root: Iteration limit reached (40), stopping Users at the start of their next task run
[2023-08-01 12:22:17,150] HUAWEI-MateBook-X-Pro.local/INFO/root: Last user stopped, quitting runner
[2023-08-01 12:22:17,255] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Shutting down (exit code 0)

By print log that I get task has run 80 times, however the arggregate results' reqs is < 80 How can i get result after all task is completed?

cyberw commented 1 year ago

[2023-08-01 14:55:21,276] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 2 ready workers [2023-08-01 14:55:21,325] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: All users spawned: {"Run": 10} (10 total users) [2023-08-01 14:55:27,645] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 1 ready workers

This looks weird (as if at first there were two workers available, but then there is only one). Did you check both worker logs?

Also, this message: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users) indicates that something was wrong/slow on the worker side. Make sure it isn't doing anything weird/extremely cpu intensive, or try increasing the env var LOCUST_WAIT_FOR_WORKERS_REPORT_AFTER_RAMP_UP to something like 5 or 10.

YeungHoiChiu commented 1 year ago

[2023-08-01 14:55:21,276] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 2 ready workers [2023-08-01 14:55:21,325] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: All users spawned: {"Run": 10} (10 total users) [2023-08-01 14:55:27,645] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 1 ready workers

This looks weird (as if at first there were two workers available, but then there is only one). Did you check both worker logs?

The logs are the same for both workers, so I just paste one of them. I don't understand why there is weired

[2023-08-01 17:17:51,415] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 2 ready workers
[2023-08-01 17:17:51,477] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: All users spawned: {"Run": 10} (10 total users)
[2023-08-01 17:17:57,599] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 1 ready workers

maybe i should show more correct message again.

here is my test code:

class Run(FastHttpUser):
    wait_time = between(0.2, 0.5)
    default_headers = global_headers
    connection_timeout = 10.0
    network_timeout = 10.0
    host = HOST
    concurrency = 20

    @task
    def test_iterations(self):
        self.client.get('/api/ecwechat/wechat/polymerize/homePage/v1?page=1&sourceType=1&tarId=-1&cursor=')

here is master command line:

(performance) kamiyeung@HUAWEI-MateBook-X-Pro performance % locust -f tmp_test_case/live.py --master --expect-workers 2 --headless -u 10 -r 10 --only-summary -i 40
[2023-08-01 17:17:50,410] HUAWEI-MateBook-X-Pro.local/INFO/root: Waiting for workers to be ready, 0 of 2 connected
[2023-08-01 17:17:50,427] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker HUAWEI-MateBook-X-Pro.local_7d2c8a4dbe0540a4b71392bbe33bd626 (index 0) reported as ready. 1 workers connected.
[2023-08-01 17:17:50,437] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker HUAWEI-MateBook-X-Pro.local_531b7843585b491c9d88e14e5c80684e (index 1) reported as ready. 2 workers connected.
[2023-08-01 17:17:51,413] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: No run time limit set, use CTRL+C to interrupt
[2023-08-01 17:17:51,415] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Starting Locust 2.15.1
[2023-08-01 17:17:51,415] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 2 ready workers
[2023-08-01 17:17:51,477] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: All users spawned: {"Run": 10} (10 total users)
[2023-08-01 17:17:57,599] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Sending spawn jobs of 10 users at 10.00 spawn rate to 1 ready workers
[2023-08-01 17:17:58,603] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users)
[2023-08-01 17:17:58,604] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker 'HUAWEI-MateBook-X-Pro.local_7d2c8a4dbe0540a4b71392bbe33bd626' (index 0) quit. 0 workers ready.
[2023-08-01 17:17:58,605] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Worker 'HUAWEI-MateBook-X-Pro.local_531b7843585b491c9d88e14e5c80684e' (index 1) quit. 0 workers ready.
[2023-08-01 17:17:58,605] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: The last worker quit, stopping test.
[2023-08-01 17:17:59,615] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Shutting down (exit code 0)
Type     Name                                                                          # reqs      # fails |    Avg     Min     Max    Med |   req/s  failures/s
--------|----------------------------------------------------------------------------|-------|-------------|-------|-------|-------|-------|--------|-----------
GET      /api/ecwechat/wechat/polymerize/homePage/v1?page=1&sourceType=1&tarId=-1&cursor=      70     0(0.00%) |    363     298     623    330 |   14.16        0.00
--------|----------------------------------------------------------------------------|-------|-------------|-------|-------|-------|-------|--------|-----------
         Aggregated                                                                        70     0(0.00%) |    363     298     623    330 |   14.16        0.00

Response time percentiles (approximated)
Type     Name                                                                                  50%    66%    75%    80%    90%    95%    98%    99%  99.9% 99.99%   100% # reqs
--------|--------------------------------------------------------------------------------|--------|------|------|------|------|------|------|------|------|------|------|------
GET      /api/ecwechat/wechat/polymerize/homePage/v1?page=1&sourceType=1&tarId=-1&cursor=      340    340    350    370    540    600    610    620    620    620    620     70
--------|--------------------------------------------------------------------------------|--------|------|------|------|------|------|------|------|------|------|------|------
         Aggregated                                                                            340    340    350    370    540    600    610    620    620    620    620     70

here is worker's command line (1)

(performance) kamiyeung@HUAWEI-MateBook-X-Pro performance % locust -f tmp_test_case/live.py --worker 
[2023-08-01 17:17:50,438] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Starting Locust 2.15.1
[2023-08-01 17:17:56,986] HUAWEI-MateBook-X-Pro.local/INFO/root: Iteration limit reached (40), stopping Users at the start of their next task run
[2023-08-01 17:17:57,511] HUAWEI-MateBook-X-Pro.local/INFO/root: Last user stopped, quitting runner
[2023-08-01 17:17:57,653] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Shutting down (exit code 0)

here is worker's command line (2)

(performance) kamiyeung@HUAWEI-MateBook-X-Pro performance % locust -f tmp_test_case/live.py --worker
[2023-08-01 17:17:50,428] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Starting Locust 2.15.1
[2023-08-01 17:17:57,121] HUAWEI-MateBook-X-Pro.local/INFO/root: Iteration limit reached (40), stopping Users at the start of their next task run
[2023-08-01 17:17:57,491] HUAWEI-MateBook-X-Pro.local/INFO/root: Last user stopped, quitting runner
[2023-08-01 17:17:57,598] HUAWEI-MateBook-X-Pro.local/INFO/locust.main: Shutting down (exit code 0)

My computer is ARM M1 pro MacBook pro

cyberw commented 1 year ago

I found the message weird because at first it says it is spawning on 2 workers but then only on 1.

Can you try adding --stop-timeout 10 on workers? (maybe also on master)

Or wait, that probably wont help. I think the problem is that workers are somehow shutting down before their final requests have been sent to master. But it shouldnt work that way. Strange.

YeungHoiChiu commented 1 year ago

I found the message weird because at first it says it is spawning on 2 workers but then only on 1.

Can you try adding --stop-timeout 10 on workers? (maybe also on master)

Or wait, that probably wont help. I think the problem is that workers are somehow shutting down before their final requests have been sent to master. But it shouldnt work that way. Strange.

Oh yes, i tried -s already , it doesn't work, I agree he problem is that workers are somehow shutting down before their final requests have been sent to master ! when I print log and save in file.log, I can count the number of task which is executed, there is 80 times log messgaes, I feel confused deeply :(

cyberw commented 1 year ago

I have found the issue, making a fix...

cyberw commented 1 year ago

Should be fixed now, available in 3.4.1 once the build finishes.

YeungHoiChiu commented 1 year ago

Should be fixed now, available in 3.4.1 once the build finishes.

Thanks! now it is worked!

YeungHoiChiu commented 1 year ago

@cyberw hello, I found the new issue that the worker still shut down before it report all the result to master when I used class TaskSet.

I had updated the locust and locust-plguins LTS.

example:

class Task(TaskSet):
    @task
    def simple_test_24(self):
        test_get_chamber_home(self, chamber_id=13)

class Run(FastHttpUser):
    wait_time = between(0.2, 0.5)
    default_headers = global_headers
    connection_timeout = 10.0
    network_timeout = 10.0
    host = HOST
    concurrency = 20
    tasks = [Task]
cyberw commented 1 year ago

What does test_get_chamber_home do? Looks like you got MORE requests than you asked for?

YeungHoiChiu commented 1 year ago

What does test_get_chamber_home do? Looks like you got MORE requests than you asked for?

NO,it just one get request like 'self.client.get()'

cyberw commented 1 year ago

So you expected to get 40 requests, and not more, right?

YeungHoiChiu commented 1 year ago

So you expected to get 40 requests, and not more, right?

yes,each worker expected to get 40 requests, I got 2 workers , when I write the task func in class User, It will get 80 requests that is what I want

cyberw commented 1 year ago

Oh, right, I mistakenly thought we automatically divided that number by the worker count (we should). And you're completely sure you are on latest locust-plugins?

YeungHoiChiu commented 1 year ago

Oh, right, I mistakenly thought we automatically divided that number by the worker count (we should). And you're completely sure you are on latest locust-plugins?

yeah, my locust-plugins' version is 3.4.2

cyberw commented 1 year ago

I dont have a lot more ideas. except maybe increase log level to debug. This log line is slightly curious:

[2023-08-07 18:24:53,703] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users)

Perhaps try removing the taskset and putting the tasks directly on the User instead to see if it makes a difference.

YeungHoiChiu commented 1 year ago

I dont have a lot more ideas. except maybe increase log level to debug. This log line is slightly curious:

[2023-08-07 18:24:53,703] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users)

Perhaps try removing the taskset and putting the tasks directly on the User instead to see if it makes a difference.

sure, here is my test result:

YeungHoiChiu commented 1 year ago

I dont have a lot more ideas. except maybe increase log level to debug. This log line is slightly curious:

[2023-08-07 18:24:53,703] HUAWEI-MateBook-X-Pro.local/INFO/locust.runners: Spawning is complete and report waittime is expired, but not all reports received from workers: {"Run": 5} (5 total users)

Perhaps try removing the taskset and putting the tasks directly on the User instead to see if it makes a difference.

cyberw commented 1 year ago

I see. Its kind of a different issue then, but I'll have a look some time. Btw, I hate TaskSets and wish they had never been implemented :)

github-actions[bot] commented 9 months ago

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 10 days.

YeungHoiChiu commented 9 months ago

This issue has not yet resolve.

github-actions[bot] commented 7 months ago

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 10 days.

YeungHoiChiu commented 6 months ago

bump

github-actions[bot] commented 4 months ago

This issue is stale because it has been open 60 days with no activity. Remove stale label or comment or this will be closed in 10 days.

github-actions[bot] commented 4 months ago

This issue was closed because it has been stalled for 10 days with no activity. This does not necessarily mean that the issue is bad, but it most likely means that nobody is willing to take the time to fix it. If you have found Locust useful, then consider contributing a fix yourself!