Add inspection modes to Python client library

dev/local/setup.cfg

@@ -24,6 +24,7 @@ packages =
     delphi.epidata.acquisition.twtr
     delphi.epidata.acquisition.wiki
     delphi.epidata.client
+    delphi.epidata.common
     delphi.epidata.server
     delphi.epidata.server.admin
     delphi.epidata.server.admin.templates

integrations/client/test_delphi_epidata.py

@@ -3,6 +3,7 @@
 # standard library
 import time
 from json import JSONDecodeError
+from requests.models import Response
 from unittest.mock import MagicMock, patch
 
 # first party
@@ -41,6 +42,8 @@ def localSetUp(self):
     # use the local instance of the Epidata API
     Epidata.BASE_URL = 'http://delphi_web_epidata/epidata'
     Epidata.auth = ('epidata', 'key')
+    Epidata.debug = False
+    Epidata.sandbox = False
 
     # use the local instance of the epidata database
     secrets.db.host = 'delphi_database_epidata'
@@ -221,6 +224,69 @@ def test_retry_request(self, get):
                        {'result': 0, 'message': 'error: Expecting value: line 1 column 1 (char 0)'}
                        )
 
+  @patch('requests.post')
+  @patch('requests.get')
+  def test_debug(self, get, post):
+    """Test that in debug mode request params are correctly logged."""
+    class MockResponse:
+      def __init__(self, content, status_code):
+          self.content = content
+          self.status_code = status_code
+      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
+
+  @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
+
   def test_geo_value(self):
     """test different variants of geo types: single, *, multi."""
 

src/client/delphi_epidata.py

@@ -10,12 +10,15 @@
 
 # External modules
 import requests
+import time
 import asyncio
 from tenacity import retry, stop_after_attempt
 
 from aiohttp import ClientSession, TCPConnector, BasicAuth
 from importlib.metadata import version, PackageNotFoundError
 
+from delphi.epidata.common.logger import get_structured_logger
+
 # Obtain package version for the user-agent. Uses the installed version by
 # preference, even if you've installed it and then use this script independently
 # by accident.
@@ -49,6 +52,10 @@ class Epidata:
 
     client_version = _version
 
+    logger = get_structured_logger('delphi_epidata_client')
+    debug = False # if True, prints extra logging statements
+    sandbox = False # if True, will not execute any queries
+
     # Helper function to cast values and/or ranges to strings
     @staticmethod
     def _listitem(value):
@@ -71,9 +78,19 @@ def _list(values):
     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}")
+        if Epidata.sandbox:
+            return
+        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}")
             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")
         # handle 401 and 429
         req.raise_for_status()
         return req
@@ -88,6 +105,8 @@ 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":