--run-time argument includes test_start event duration since the upgrade to v2

[varvarvarvar]

Describe the bug

The behaviour of --run-time argument has changed since the upgrade to v2. In later versions, it controls the total duration of the test including test_start event, while in v1 it doesn't include the duration of test_start event.

I looked through Changelog Highlights and github issues, but couldn't find any information about it.

Expected behavior

If we run a load test with locust 1.6.0 and specify --run-time 15s, test_start event is executed before we set the time limit of 15s:

$ time locust -f locustfile.py --host localhost --headless -u 1 -r 1 --run-time 15s

[2023-03-16 12:52:34,114] host/INFO/root: Starting on_test_start
[2023-03-16 12:52:49,118] host/INFO/root: Ending on_test_start
[2023-03-16 12:52:49,118] host/INFO/locust.main: Run time limit set to 15 seconds
[2023-03-16 12:52:49,118] host/INFO/locust.main: Starting Locust 1.6.0
[2023-03-16 12:52:49,119] host/INFO/locust.runners: Spawning 1 users at the rate 1 users/s (0 users already running)...
[2023-03-16 12:52:49,119] host/INFO/locust.runners: All users spawned: WebsiteUser: 1 (1 total running)
...
[2023-03-16 12:52:49,120] host/INFO/root: Testing myfunc
[2023-03-16 12:52:49,121] host/INFO/root: Testing myfunc
...
real	0m30.520s
user	0m14.588s
sys	0m0.920s

Actual behavior

If we run a load test with locust 2.15.1 and specify --run-time 15s, the duration of test_start event is included in these 15s:

$ time locust -f locustfile.py --host localhost --headless -u 1 -r 1 --run-time 15s

[2023-03-16 12:58:30,670] host/INFO/locust.main: Run time limit set to 15 seconds
[2023-03-16 12:58:30,670] host/INFO/locust.main: Starting Locust 2.15.1
...
[2023-03-16 12:58:30,671] host/INFO/root: Starting on_test_start
...
[2023-03-16 12:58:45,337] host/INFO/locust.main: --run-time limit reached, shutting down
[2023-03-16 12:58:45,338] host/INFO/locust.main: Shutting down (exit code 0)
...
real	0m15.284s
user	0m0.576s
sys	0m0.057s

Steps to reproduce

Run the specified command on locustfile.py with locust 1.6.0 and 2.15.1.

Environment

• OS: Ubuntu 20.04.3
• Python version: 3.10.8
• Locust version: 2.15.1
• Locust command line that you ran: time locust -f locustfile.py --host localhost --headless -u 1 -r 1 --run-time 15s
• Locust file contents (anonymized if necessary):

import logging
import time

from locust import HttpUser, events, task


@events.test_start.add_listener
def on_test_start(environment, **kw):
    logging.info("Starting on_test_start")
    time.sleep(15)
    logging.info("Ending on_test_start")


class WebsiteUser(HttpUser):
    @task
    def myfunc(self):
        logging.info("Testing myfunc")

Workaround

init event can be used instead of on_start event after upgrading to v2 as its duration is not included in the run time specified by --run-time argument.

[cyberw]

Interesting. I dont remember if this was a deliberate change or an accidental one, and I'm not sure which version makes the most sense/is most expected. Probably want to leave it as is, but we could document it better.

At some point there was a risk that Users got started before test_start had finished, maybe that was the behaviour in 1.x.

[github-actions]

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!

[cyberw]

I'll try to fix this soon...

[cyberw]

Hmm. I took another swing at this, but it's really hard to do without some serious refactoring.

The main function doesn't know anything about test_start, and the Runner (that calls test_start) can't stop the whole test, even if we told it about the run time, because it has no idea about things like the web UI, that need to be shut down.