Merge pull request #2021 from keflavich/fix_logging

BUGFIX: Logger will try to download too-large files

Author: C. E. Brasseur

astroquery/alma/tests/test_alma_remote.py

@@ -677,3 +677,23 @@ def test_staging_stacking(dataarchive_url):
 
     alma.stage_data(['uid://A001/X13d5/X1d', 'uid://A002/X3216af/X31',
                      'uid://A001/X12a3/X240'])
+
+
+@pytest.mark.remote_data
+@pytest.mark.skipif("SKIP_SLOW", "Huge data file download")
+@pytest.mark.parametrize('dataarchive_url', _test_url_list)
+def test_big_download_regression(dataarchive_url):
+    """
+    Regression test for #2020/#2021 - this download fails if logging tries to
+    load the whole data file into memory.
+    """
+    result = Alma.query({'project_code': '2013.1.01365.S'})
+    uids = np.unique(result['member_ous_uid'])
+    files = Alma.get_data_info(uids)
+
+    # we may need to change the cache dir for this to work on testing machines?
+    # savedir='/big/data/path/'
+    # Alma.cache_dir=savedir
+
+    # this is a big one that fails
+    Alma.download_files([files['access_url'][3]])

astroquery/query.py

@@ -172,26 +172,38 @@ def __call__(self, *args, **kwargs):
         return self.__class__(*args, **kwargs)
 
     def _response_hook(self, response, *args, **kwargs):
-        # Log request at INFO severity
-        request_hdrs = '\n'.join(f'{k}: {v}' for k, v in response.request.headers.items())
-        request_log = textwrap.indent(
-            f"-----------------------------------------\n"
-            f"{response.request.method} {response.request.url}\n"
-            f"{request_hdrs}\n"
-            f"\n"
-            f"{response.request.body}\n"
-            f"-----------------------------------------", '\t')
-        log.debug(f"HTTP request\n{request_log}")
-        # Log response at DEBUG severity
-        response_hdrs = '\n'.join(f'{k}: {v}' for k, v in response.headers.items())
-        response_log = textwrap.indent(
-            f"-----------------------------------------\n"
-            f"{response.status_code} {response.reason} {response.url}\n"
-            f"{response_hdrs}\n"
-            f"\n"
-            f"{response.text}\n"
-            f"-----------------------------------------", '\t')
-        log.log(5, f"HTTP response\n{response_log}")
+        loglevel = log.getEffectiveLevel()
+
+        if loglevel >= 10:
+            # Log request at DEBUG severity
+            request_hdrs = '\n'.join(f'{k}: {v}' for k, v in response.request.headers.items())
+            request_log = textwrap.indent(
+                f"-----------------------------------------\n"
+                f"{response.request.method} {response.request.url}\n"
+                f"{request_hdrs}\n"
+                f"\n"
+                f"{response.request.body}\n"
+                f"-----------------------------------------", '\t')
+            log.debug(f"HTTP request\n{request_log}")
+        if loglevel >= 5:
+            # Log response at super-DEBUG severity
+            response_hdrs = '\n'.join(f'{k}: {v}' for k, v in response.headers.items())
+            if kwargs.get('stream'):
+                response_log = textwrap.indent(
+                    f"-----------------------------------------\n"
+                    f"{response.status_code} {response.reason} {response.url}\n"
+                    f"{response_hdrs}\n"
+                    "Streaming Data\n"
+                    f"-----------------------------------------", '\t')
+            else:
+                response_log = textwrap.indent(
+                    f"-----------------------------------------\n"
+                    f"{response.status_code} {response.reason} {response.url}\n"
+                    f"{response_hdrs}\n"
+                    f"\n"
+                    f"{response.text}\n"
+                    f"-----------------------------------------", '\t')
+            log.log(5, f"HTTP response\n{response_log}")
 
     def _request(self, method, url,
                  params=None, data=None, headers=None,
@@ -387,6 +399,9 @@ def _download_file(self, url, local_filepath, timeout=None, auth=None,
 
         blocksize = astropy.utils.data.conf.download_block_size
 
+        log.debug(f"Downloading URL {url} to {local_filepath} with size {length} "
+                  f"by blocks of {blocksize}")
+
         bytes_read = 0
 
         # Only show progress bar if logging level is INFO or lower.