Clear logger txn_id after making requests

Otherwise, transaction IDs start bleeding over to messages where they
don't make sense.

Change-Id: I7cf1b0ee7f928fcaa89a799a734e0d028d705383

swift/common/internal_client.py

@@ -13,7 +13,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
-from eventlet import sleep, Timeout
+from eventlet import sleep, Timeout, spawn
 from eventlet.green import httplib, socket
 import json
 import six
@@ -202,7 +202,8 @@ class InternalClient(object):
             if params:
                 req.params = params
             try:
-                resp = req.get_response(self.app)
+                # execute in a separate greenthread to not polute corolocals
+                resp = spawn(req.get_response, self.app).wait()
             except (Exception, Timeout):
                 exc_type, exc_value, exc_traceback = exc_info()
             else:

swift/container/sharder.py

@@ -914,34 +914,31 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
         if newest:
             headers['X-Newest'] = 'true'
         try:
-            try:
-                resp = self.int_client.make_request(
-                    'GET', path, headers, acceptable_statuses=(2,),
-                    params=params)
-            except internal_client.UnexpectedResponse as err:
-                self.logger.warning("Failed to get shard ranges from %s: %s",
-                                    quote(broker.root_path), err)
-                return None
-            record_type = resp.headers.get('x-backend-record-type')
-            if record_type != 'shard':
-                err = 'unexpected record type %r' % record_type
-                self.logger.error("Failed to get shard ranges from %s: %s",
-                                  quote(broker.root_path), err)
-                return None
-
-            try:
-                data = json.loads(resp.body)
-                if not isinstance(data, list):
-                    raise ValueError('not a list')
-                return [ShardRange.from_dict(shard_range)
-                        for shard_range in data]
-            except (ValueError, TypeError, KeyError) as err:
-                self.logger.error(
-                    "Failed to get shard ranges from %s: invalid data: %r",
-                    quote(broker.root_path), err)
+            resp = self.int_client.make_request(
+                'GET', path, headers, acceptable_statuses=(2,),
+                params=params)
+        except internal_client.UnexpectedResponse as err:
+            self.logger.warning("Failed to get shard ranges from %s: %s",
+                                quote(broker.root_path), err)
             return None
-        finally:
-            self.logger.txn_id = None
+        record_type = resp.headers.get('x-backend-record-type')
+        if record_type != 'shard':
+            err = 'unexpected record type %r' % record_type
+            self.logger.error("Failed to get shard ranges from %s: %s",
+                              quote(broker.root_path), err)
+            return None
+
+        try:
+            data = json.loads(resp.body)
+            if not isinstance(data, list):
+                raise ValueError('not a list')
+            return [ShardRange.from_dict(shard_range)
+                    for shard_range in data]
+        except (ValueError, TypeError, KeyError) as err:
+            self.logger.error(
+                "Failed to get shard ranges from %s: invalid data: %r",
+                quote(broker.root_path), err)
+        return None
 
     def _put_container(self, node, part, account, container, headers, body):
         try:

test/unit/common/test_internal_client.py

@@ -25,7 +25,8 @@ from textwrap import dedent
 import six
 from six.moves import range, zip_longest
 from six.moves.urllib.parse import quote, parse_qsl
-from swift.common import exceptions, internal_client, request_helpers, swob
+from swift.common import exceptions, internal_client, request_helpers, swob, \
+    utils
 from swift.common.header_key_dict import HeaderKeyDict
 from swift.common.storage_policy import StoragePolicy
 from swift.common.middleware.proxy_logging import ProxyLoggingMiddleware
@@ -347,6 +348,35 @@ class TestInternalClient(unittest.TestCase):
         client = InternalClient(self)
         client.make_request('GET', '/', {}, (200,))
 
+    def test_make_request_clears_txn_id_after_calling_app(self):
+        class InternalClient(internal_client.InternalClient):
+            def __init__(self, test, logger):
+                def fake_app(env, start_response):
+                    self.app.logger.txn_id = 'foo'
+                    self.app.logger.debug('Inside of request')
+                    start_response('200 Ok', [('Content-Length', '0')])
+                    return []
+
+                self.test = test
+                self.user_agent = 'some_agent'
+                self.app = fake_app
+                self.app.logger = logger
+                self.request_tries = 1
+                self.use_replication_network = False
+
+        fake_logger = debug_logger()
+        logger = utils.LogAdapter(fake_logger, 'test-server')
+        logger.debug('Before request')
+        client = InternalClient(self, logger)
+        client.make_request('GET', '/', {}, (200,))
+        logger.debug('After request')
+        self.assertEqual([(args[0], kwargs['extra'].get('txn_id'))
+                          for args, kwargs in fake_logger.log_dict['debug']], [
+            ('Before request', None),
+            ('Inside of request', 'foo'),
+            ('After request', None),
+        ])
+
     def test_make_request_defaults_replication_network_header(self):
         class InternalClient(internal_client.InternalClient):
             def __init__(self, test):