diff --git a/locust/clients.py b/locust/clients.py index 9e8ae2f6a8..c4f3d385bc 100644 --- a/locust/clients.py +++ b/locust/clients.py @@ -130,9 +130,15 @@ def request(self, method, url, name=None, catch_response=False, context={}, **kw # prepend url with hostname unless it's already an absolute URL url = self._build_url(url) + # use stream=True to avoid closing socket and downloading content at the beginning + # we'll download content if actually requested a bit later + # + # a bit of a hack to actually estimate fetching time + stream = kwargs.pop("stream", False) + start_time = time.time() start_perf_counter = time.perf_counter() - response = self._send_request_safe_mode(method, url, **kwargs) + response = self._send_request_safe_mode(method, url, **kwargs, stream=True) server_response_time = time.perf_counter() request_before_redirect = (response.history and response.history[0] or response).request @@ -158,7 +164,7 @@ def request(self, method, url, name=None, catch_response=False, context={}, **kw # get the length of the content, but if the argument stream is set to True, we take # the size from the content-length header, in order to not trigger fetching of the body - if kwargs.get("stream", False): + if stream: request_meta["response_length"] = int(response.headers.get("content-length") or 0) else: request_meta["response_length"] = len(response.content or b"") diff --git a/locust/test/test_fasthttp.py b/locust/test/test_fasthttp.py index 70f5d37f45..c379083156 100644 --- a/locust/test/test_fasthttp.py +++ b/locust/test/test_fasthttp.py @@ -70,6 +70,37 @@ def test_streaming_response(self): # download the content of the streaming response (so we don't get an ugly exception in the log) _ = r.content + def test_response_times_are_separated_in_request_metadata(self): + """ + Test that request times for server response and fetching are accessible + in request metadata + """ + kwargs = {} + def on_request(**kw): + kwargs.update(kw) + self.environment.events.request.add_listener(on_request) + s = self.get_client() + + # Verify that fetching content time is close to 0, when stream=True + s.get("/streaming/50", stream=True) + self.assertGreater(kwargs["response_waiting_time"], 0) + self.assertLess(kwargs["response_waiting_time"], 250) + self.assertLess(kwargs["response_fetching_time"], 10) + self.assertAlmostEqual( + self.runner.stats.get("/streaming/50", method="GET").avg_response_time, + kwargs["response_waiting_time"] + kwargs["response_fetching_time"], delta=0.1) + self.runner.stats.clear_all() + kwargs.clear() + + # Now that we actually check fetching time + s.get("/streaming/50") + self.assertGreater(kwargs["response_waiting_time"], 0) + self.assertLess(kwargs["response_waiting_time"], 250) + self.assertGreater(kwargs["response_fetching_time"], 250) + self.assertAlmostEqual( + self.runner.stats.get("/streaming/50", method="GET").avg_response_time, + kwargs["response_waiting_time"] + kwargs["response_fetching_time"], delta=0.1) + def test_slow_redirect(self): s = self.get_client() url = "/redirect?url=/redirect&delay=0.5" diff --git a/locust/test/test_http.py b/locust/test/test_http.py index 0cf7d71728..47d3e471d0 100644 --- a/locust/test/test_http.py +++ b/locust/test/test_http.py @@ -61,6 +61,38 @@ def test_streaming_response(self): # download the content of the streaming response (so we don't get an ugly exception in the log) _ = r.content + def test_response_times_are_separated_in_request_metadata(self): + """ + Test that request times for server response and fetching are accessible + in request metadata + """ + kwargs = {} + def on_request(**kw): + kwargs.update(kw) + self.environment.events.request.add_listener(on_request) + s = self.get_client() + + # Verify that fetching content time is close to 0, when stream=True + s.get("/streaming/50", stream=True) + self.assertGreater(kwargs["response_waiting_time"], 0) + self.assertLess(kwargs["response_waiting_time"], 250) + self.assertLess(kwargs["response_fetching_time"], 10) + self.assertAlmostEqual( + self.runner.stats.get("/streaming/50", method="GET").avg_response_time, + kwargs["response_waiting_time"] + kwargs["response_fetching_time"], delta=0.1) + self.runner.stats.clear_all() + kwargs.clear() + + # Now that we actually check fetching time + s.get("/streaming/50") + self.assertGreater(kwargs["response_waiting_time"], 0) + self.assertLess(kwargs["response_waiting_time"], 250) + self.assertGreater(kwargs["response_fetching_time"], 250) + self.assertAlmostEqual( + self.runner.stats.get("/streaming/50", method="GET").avg_response_time, + kwargs["response_waiting_time"] + kwargs["response_fetching_time"], delta=0.1) + + def test_slow_redirect(self): s = self.get_client() url = "/redirect?url=/redirect&delay=0.5"