Make backend container requests use the same X-Timestamp

The proxy.controllers.base's generate_request_headers will set an X-Timestamp
header for you if it didn't get populated by additional kwarg or the
transfer_headers method.  This works fine if you only call it once per
request, but because of how proxy.controllers.obj and
proxy.controllers.container fill in the backend update header chains in
_backend_requests we need multiple independent copies and call the base
controllers generate_request_headers once of each backend request - which left
the ContainerController sending down different X-Timestamp values
(microseconds apart) for PUT and DELETE.

The ObjectController skirts the issue entirely because it always preloads a
X-Timestamp on the req used to generate backend headers, and it allows it to
be copied over via transfer_headers by including 'x-timestamp' in it's
pass_through_headers attribute.

Because the container-replicator is already does merge_timestamps the
differences would always eventaully even out and there is no consistency bug,
but this seems cleaner since they put_timestamp being stored on the three
replicas during a container PUT were all coming from the same client request.

Since both PUT and DELETE were effected, and the ContainerController doesn't
need to allow X-Timestamp to pass_through like the ObjectController does for
container-sync, it seemed cleanest to fix the issue in _backend_requests via
the additional kwarg to generate_request_headers.

There's a driveby fix for FakeLogger and update to the proxy_server's
ContainerController tests.

Change-Id: Idbdf1204da33f8fb356ae35961dbdc931b228b77

swift/proxy/controllers/container.py

@@ -15,8 +15,9 @@
 
 from swift import gettext_ as _
 from urllib import unquote
+import time
 
-from swift.common.utils import public, csv_append
+from swift.common.utils import public, csv_append, normalize_timestamp
 from swift.common.constraints import check_metadata, MAX_CONTAINER_NAME_LENGTH
 from swift.common.http import HTTP_ACCEPTED
 from swift.proxy.controllers.base import Controller, delay_denial, \
@@ -182,7 +183,9 @@ class ContainerController(Controller):
 
     def _backend_requests(self, req, n_outgoing,
                           account_partition, accounts):
-        headers = [self.generate_request_headers(req, transfer=True)
+        additional = {'X-Timestamp': normalize_timestamp(time.time())}
+        headers = [self.generate_request_headers(req, transfer=True,
+                                                 additional=additional)
                    for _junk in range(n_outgoing)]
 
         for i, account in enumerate(accounts):

test/unit/__init__.py

@@ -235,6 +235,7 @@ class FakeLogger(logging.Logger):
         if 'facility' in kwargs:
             self.facility = kwargs['facility']
         self.statsd_client = None
+        self.thread_locals = None
 
     def _clear(self):
         self.log_dict = defaultdict(list)

test/unit/proxy/test_server.py

@@ -27,6 +27,7 @@ from urllib import quote
 from hashlib import md5
 from tempfile import mkdtemp
 import weakref
+import re
 
 import mock
 from eventlet import sleep, spawn, wsgi, listen
@@ -4134,7 +4135,8 @@ class TestContainerController(unittest.TestCase):
         self.app = proxy_server.Application(None, FakeMemcache(),
                                             account_ring=FakeRing(),
                                             container_ring=FakeRing(),
-                                            object_ring=FakeRing())
+                                            object_ring=FakeRing(),
+                                            logger=FakeLogger())
 
     def test_transfer_headers(self):
         src_headers = {'x-remove-versions-location': 'x',
@@ -5056,6 +5058,55 @@ class TestContainerController(unittest.TestCase):
              'X-Account-Device': 'sdc'}
         ])
 
+    def test_PUT_backed_x_timestamp_header(self):
+        timestamps = []
+
+        def capture_timestamps(*args, **kwargs):
+            headers = kwargs['headers']
+            timestamps.append(headers.get('X-Timestamp'))
+
+        req = Request.blank('/v1/a/c', method='PUT', headers={'': ''})
+        with save_globals():
+            new_connect = set_http_connect(200,  # account existance check
+                                           201, 201, 201,
+                                           give_connect=capture_timestamps)
+            resp = self.app.handle_request(req)
+
+        # sanity
+        self.assertRaises(StopIteration, new_connect.code_iter.next)
+        self.assertEqual(2, resp.status_int // 100)
+
+        timestamps.pop(0)  # account existance check
+        self.assertEqual(3, len(timestamps))
+        for timestamp in timestamps:
+            self.assertEqual(timestamp, timestamps[0])
+            self.assert_(re.match('[0-9]{10}\.[0-9]{5}', timestamp))
+
+    def test_DELETE_backed_x_timestamp_header(self):
+        timestamps = []
+
+        def capture_timestamps(*args, **kwargs):
+            headers = kwargs['headers']
+            timestamps.append(headers.get('X-Timestamp'))
+
+        req = Request.blank('/v1/a/c', method='DELETE', headers={'': ''})
+        self.app.update_request(req)
+        with save_globals():
+            new_connect = set_http_connect(200,  # account existance check
+                                           201, 201, 201,
+                                           give_connect=capture_timestamps)
+            resp = self.app.handle_request(req)
+
+        # sanity
+        self.assertRaises(StopIteration, new_connect.code_iter.next)
+        self.assertEqual(2, resp.status_int // 100)
+
+        timestamps.pop(0)  # account existance check
+        self.assertEqual(3, len(timestamps))
+        for timestamp in timestamps:
+            self.assertEqual(timestamp, timestamps[0])
+            self.assert_(re.match('[0-9]{10}\.[0-9]{5}', timestamp))
+
     def test_node_read_timeout_retry_to_container(self):
         with save_globals():
             req = Request.blank('/v1/a/c', environ={'REQUEST_METHOD': 'GET'})