X-Git-Url: https://git.arvados.org/arvados.git/blobdiff_plain/11cf3f097fa7d9f10c0131791249c56aab6839a6..1efba8f3b728a3b8aa3c64c5aa09f441318ff2a8:/sdk/python/tests/test_api.py

diff --git a/sdk/python/tests/test_api.py b/sdk/python/tests/test_api.py
index e54f387b39..0f85e5520c 100644
--- a/sdk/python/tests/test_api.py
+++ b/sdk/python/tests/test_api.py
@@ -11,6 +11,7 @@ import contextlib
 import httplib2
 import itertools
 import json
+import logging
 import mimetypes
 import os
 import socket
@@ -29,8 +30,10 @@ from arvados.api import (
     normalize_api_kwargs,
     api_kwargs_from_config,
     OrderedJsonModel,
+    _googleapiclient_log_lock,
 )
 from .arvados_testutil import fake_httplib2_response, mock_api_responses, queue_with
+import httplib2.error
 
 if not mimetypes.inited:
     mimetypes.init()
@@ -168,7 +171,10 @@ class ArvadosApiTest(run_test_server.TestCaseWithServers):
 
     def test_4xx_not_retried(self):
         client = arvados.api('v1', num_retries=3)
-        for code in [400, 401, 404, 422]:
+        # Note that googleapiclient does retry 403 *if* the response JSON
+        # includes flags that say the request was denied by rate limiting.
+        # An empty JSON response like we use here should not be retried.
+        for code in [400, 401, 403, 404, 422]:
             with self.subTest(f'error {code}'), mock.patch('time.sleep'):
                 with mock_api_responses(
                         client,
@@ -388,6 +394,46 @@ class ArvadosApiTest(run_test_server.TestCaseWithServers):
                 args[arg_index] = arg_value
                 api_client(*args, insecure=True)
 
+    def test_initial_retry_logs(self):
+        try:
+            _googleapiclient_log_lock.release()
+        except RuntimeError:
+            # Lock was never acquired - that's the state we want anyway
+            pass
+        real_logger = logging.getLogger('googleapiclient.http')
+        mock_logger = mock.Mock(wraps=real_logger)
+        mock_logger.handlers = logging.getLogger('googleapiclient').handlers
+        mock_logger.level = logging.NOTSET
+        with mock.patch('logging.getLogger', return_value=mock_logger), \
+             mock.patch('time.sleep'), \
+             self.assertLogs(real_logger, 'INFO') as actual_logs:
+            try:
+                api_client('v1', 'https://test.invalid/', 'NoToken', num_retries=1)
+            except httplib2.error.ServerNotFoundError:
+                pass
+        mock_logger.addFilter.assert_called()
+        mock_logger.addHandler.assert_called()
+        mock_logger.setLevel.assert_called()
+        mock_logger.removeHandler.assert_called()
+        mock_logger.removeFilter.assert_called()
+        self.assertRegex(actual_logs.output[0], r'^INFO:googleapiclient\.http:Sleeping \d')
+
+    def test_configured_logger_untouched(self):
+        real_logger = logging.getLogger('googleapiclient.http')
+        mock_logger = mock.Mock(wraps=real_logger)
+        mock_logger.handlers = logging.getLogger().handlers
+        with mock.patch('logging.getLogger', return_value=mock_logger), \
+             mock.patch('time.sleep'):
+            try:
+                api_client('v1', 'https://test.invalid/', 'NoToken', num_retries=1)
+            except httplib2.error.ServerNotFoundError:
+                pass
+        mock_logger.addFilter.assert_not_called()
+        mock_logger.addHandler.assert_not_called()
+        mock_logger.setLevel.assert_not_called()
+        mock_logger.removeHandler.assert_not_called()
+        mock_logger.removeFilter.assert_not_called()
+
 
 class ConstructNumRetriesTestCase(unittest.TestCase):
     @staticmethod