Update based on reviews

Author: rzats

integrations/client/test_delphi_epidata.py

@@ -236,56 +236,69 @@ def raise_for_status(self): pass
 
     Epidata.debug = True
 
-    with self.subTest(name='test multiple GET'):
-      with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
-        get.reset_mock()
-        get.return_value = MockResponse(b'{"key": "value"}', 200)
-        Epidata._request_with_retry("test_endpoint1", params={"key1": "value1"})
-        Epidata._request_with_retry("test_endpoint2", params={"key2": "value2"})
-
-      output = logs.output
-      self.assertEqual(len(output), 4) # [request, response, request, response]
-      self.assertIn("Sending GET request to URL: http://delphi_web_epidata/epidata/test_endpoint1/", output[0])
-      self.assertIn("params: {'key1': 'value1'}", output[0])
-      self.assertIn("Received 200 response (16 bytes)", output[1])
-      self.assertIn("Sending GET request to URL: http://delphi_web_epidata/epidata/test_endpoint2/", output[2])
-      self.assertIn("params: {'key2': 'value2'}", output[2])
-      self.assertIn("Received 200 response (16 bytes)", output[3])
-
-    with self.subTest(name='test GET and POST'):
-      with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
-        get.reset_mock()
-        get.return_value = MockResponse(b'{"key": "value"}', 414)
-        post.reset_mock()
-        post.return_value = MockResponse(b'{"key": "value"}', 200)
-        Epidata._request_with_retry("test_endpoint3", params={"key3": "value3"})
-
-      output = logs.output
-      self.assertEqual(len(output), 4) # [request, response, request, response]
-      self.assertIn("Sending GET request to URL: http://delphi_web_epidata/epidata/test_endpoint3/", output[0])
-      self.assertIn("params: {'key3': 'value3'}", output[0])
-      self.assertIn("Received 414 response (16 bytes)", output[1])
-      self.assertIn("Sending POST request to URL: http://delphi_web_epidata/epidata/test_endpoint3/", output[2])
-      self.assertIn("params: {'key3': 'value3'}", output[2])
-      self.assertIn("Received 200 response (16 bytes)", output[3])
-    
-    Epidata.debug = False
+    try:
+      with self.subTest(name='test multiple GET'):
+        with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
+          get.reset_mock()
+          get.return_value = MockResponse(b'{"key": "value"}', 200)
+          Epidata._request_with_retry("test_endpoint1", params={"key1": "value1"})
+          Epidata._request_with_retry("test_endpoint2", params={"key2": "value2"})
+
+        output = logs.output
+        self.assertEqual(len(output), 4) # [request, response, request, response]
+        self.assertIn("Sending GET request", output[0])
+        self.assertIn("\"url\": \"http://delphi_web_epidata/epidata/test_endpoint1/\"", output[0])
+        self.assertIn("\"params\": {\"key1\": \"value1\"}", output[0])
+        self.assertIn("Received response", output[1])
+        self.assertIn("\"status_code\": 200", output[1])
+        self.assertIn("\"len\": 16", output[1])
+        self.assertIn("Sending GET request", output[2])
+        self.assertIn("\"url\": \"http://delphi_web_epidata/epidata/test_endpoint2/\"", output[2])
+        self.assertIn("\"params\": {\"key2\": \"value2\"}", output[2])
+        self.assertIn("Received response", output[3])
+        self.assertIn("\"status_code\": 200", output[3])
+        self.assertIn("\"len\": 16", output[3])
+
+      with self.subTest(name='test GET and POST'):
+        with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
+          get.reset_mock()
+          get.return_value = MockResponse(b'{"key": "value"}', 414)
+          post.reset_mock()
+          post.return_value = MockResponse(b'{"key": "value"}', 200)
+          Epidata._request_with_retry("test_endpoint3", params={"key3": "value3"})
+
+        output = logs.output
+        self.assertEqual(len(output), 3) # [request, response, request, response]
+        self.assertIn("Sending GET request", output[0])
+        self.assertIn("\"url\": \"http://delphi_web_epidata/epidata/test_endpoint3/\"", output[0])
+        self.assertIn("\"params\": {\"key3\": \"value3\"}", output[0])
+        self.assertIn("Received 414 response, retrying as POST request", output[1])
+        self.assertIn("\"url\": \"http://delphi_web_epidata/epidata/test_endpoint3/\"", output[1])
+        self.assertIn("\"params\": {\"key3\": \"value3\"}", output[1])
+        self.assertIn("Received response", output[2])
+        self.assertIn("\"status_code\": 200", output[2])
+        self.assertIn("\"len\": 16", output[2])
+    finally: # make sure this global is always reset
+      Epidata.debug = False
 
   @patch('requests.post')
   @patch('requests.get')
   def test_sandbox(self, get, post):
     """Test that in debug + sandbox mode request params are correctly logged, but no queries are sent."""
     Epidata.debug = True
     Epidata.sandbox = True
-    with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
-      Epidata.covidcast('src', 'sig', 'day', 'county', 20200414, '01234')
-    output = logs.output
-    self.assertEqual(len(output), 1)
-    self.assertIn("Sending GET request to URL: http://delphi_web_epidata/epidata/covidcast/", output[0])
-    get.assert_not_called()
-    post.assert_not_called()
-    Epidata.debug = False
-    Epidata.sandbox = False
+    try:
+      with self.assertLogs('delphi_epidata_client', level='INFO') as logs:
+        Epidata.covidcast('src', 'sig', 'day', 'county', 20200414, '01234')
+      output = logs.output
+      self.assertEqual(len(output), 1)
+      self.assertIn("Sending GET request", output[0])
+      self.assertIn("\"url\": \"http://delphi_web_epidata/epidata/covidcast/\"", output[0])
+      get.assert_not_called()
+      post.assert_not_called()
+    finally: # make sure these globals are always reset
+      Epidata.debug = False
+      Epidata.sandbox = False
 
   def test_geo_value(self):
     """test different variants of geo types: single, *, multi."""

src/client/delphi_epidata.py

@@ -79,18 +79,24 @@ def _request_with_retry(endpoint, params={}):
         """Make request with a retry if an exception is thrown."""
         request_url = f"{Epidata.BASE_URL}/{endpoint}/"
         if Epidata.debug:
-            Epidata.logger.info(f"Sending GET request to URL: {request_url} | params: {params} | headers: {_HEADERS}")
+            Epidata.logger.info("Sending GET request", url=request_url, params=params, headers=_HEADERS)
         if Epidata.sandbox:
-            return
+            resp = requests.Response()
+            resp._content = b'true'
+            return resp
         start_time = time.time()
         req = requests.get(request_url, params, auth=Epidata.auth, headers=_HEADERS)
         if req.status_code == 414:
             if Epidata.debug:
-                Epidata.logger.info(f"Received {req.status_code} response ({len(req.content)} bytes) in {(time.time() - start_time):.3f} seconds")
-                Epidata.logger.info(f"Sending POST request to URL: {request_url} | params: {params} | headers: {_HEADERS}")
+                Epidata.logger.info("Received 414 response, retrying as POST request", url=request_url, params=params, headers=_HEADERS)
             req = requests.post(request_url, params, auth=Epidata.auth, headers=_HEADERS)
         if Epidata.debug:
-            Epidata.logger.info(f"Received {req.status_code} response ({len(req.content)} bytes) in {(time.time() - start_time):.3f} seconds")
+            Epidata.logger.info(
+                "Received response",
+                status_code=req.status_code,
+                len=len(req.content),
+                time=round(time.time() - start_time, 4)
+            )
         # handle 401 and 429
         req.raise_for_status()
         return req
@@ -105,8 +111,6 @@ def _request(endpoint, params={}):
         """
         try:
             result = Epidata._request_with_retry(endpoint, params)
-            if Epidata.sandbox:
-                return
         except Exception as e:
             return {"result": 0, "message": "error: " + str(e)}
         if params is not None and "format" in params and params["format"] == "csv":