Adding adjustment to standard HttpSession and adding tests

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"")

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"

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"