From 00ab3d4f36a1e994698f7ab1ecada1cefa72e8db Mon Sep 17 00:00:00 2001 From: gholt Date: Sat, 20 Apr 2013 03:34:48 +0000 Subject: [PATCH] Included time inside trans_id Including the time inside the trans_id can be very useful for knowing which logs to scan. I made this so the trans_id will still be the same length (the randomness of the remaining uuid4 should be enough for this use). I also added a convenience function for retreiving the time information from a trans_id. If you're wondering why I just didn't use uuid1 that embeds the time, it's because it also embeds uuid.getnode() which "The first time this runs, it may launch a separate program, which could be quite slow." We could supply our own getnode value, but then we have to guarantee its uniqueness, yada yada yada. Change-Id: Ie33caf1e839fd1a21b01a928a8b301126bef7396 --- swift/common/middleware/catch_errors.py | 5 ++-- swift/common/utils.py | 15 ++++++++++ swift/proxy/server.py | 5 ++-- test/unit/common/test_utils.py | 37 +++++++++++++++++++++++++ 4 files changed, 56 insertions(+), 6 deletions(-) diff --git a/swift/common/middleware/catch_errors.py b/swift/common/middleware/catch_errors.py index 8159c47043..35ff2eb44d 100644 --- a/swift/common/middleware/catch_errors.py +++ b/swift/common/middleware/catch_errors.py @@ -14,10 +14,9 @@ # limitations under the License. from eventlet import Timeout -import uuid from swift.common.swob import Request, HTTPServerError -from swift.common.utils import get_logger +from swift.common.utils import get_logger, generate_trans_id from swift.common.wsgi import WSGIContext @@ -29,7 +28,7 @@ class CatchErrorsContext(WSGIContext): self.trans_id_suffix = trans_id_suffix def handle_request(self, env, start_response): - trans_id = 'tx' + uuid.uuid4().hex + self.trans_id_suffix + trans_id = generate_trans_id(self.trans_id_suffix) env['swift.trans_id'] = trans_id self.logger.txn_id = trans_id try: diff --git a/swift/common/utils.py b/swift/common/utils.py index c35569bdfd..4853dd6d4a 100644 --- a/swift/common/utils.py +++ b/swift/common/utils.py @@ -21,6 +21,7 @@ import os import pwd import sys import time +import uuid import functools from hashlib import md5 from random import random, shuffle @@ -178,6 +179,20 @@ def get_param(req, name, default=None): return value +def generate_trans_id(trans_id_suffix): + return 'tx%s-%010x%s' % ( + uuid.uuid4().hex[:21], time.time(), trans_id_suffix) + + +def get_trans_id_time(trans_id): + if len(trans_id) >= 34 and trans_id[:2] == 'tx' and trans_id[23] == '-': + try: + return int(trans_id[24:34], 16) + except ValueError: + pass + return None + + class FallocateWrapper(object): def __init__(self, noop=False): diff --git a/swift/proxy/server.py b/swift/proxy/server.py index 4f19868d10..65dd1e3f12 100644 --- a/swift/proxy/server.py +++ b/swift/proxy/server.py @@ -27,7 +27,6 @@ import mimetypes import os from ConfigParser import ConfigParser -import uuid from random import shuffle from time import time @@ -35,7 +34,7 @@ from eventlet import Timeout from swift.common.ring import Ring from swift.common.utils import cache_from_env, get_logger, \ - get_remote_client, split_path, config_true_value + get_remote_client, split_path, config_true_value, generate_trans_id from swift.common.constraints import check_utf8 from swift.proxy.controllers import AccountController, ObjectController, \ ContainerController @@ -221,7 +220,7 @@ class Application(object): controller = controller(self, **path_parts) if 'swift.trans_id' not in req.environ: # if this wasn't set by an earlier middleware, set it now - trans_id = 'tx' + uuid.uuid4().hex + self.trans_id_suffix + trans_id = generate_trans_id(self.trans_id_suffix) req.environ['swift.trans_id'] = trans_id self.logger.txn_id = trans_id req.headers['x-trans-id'] = req.environ['swift.trans_id'] diff --git a/test/unit/common/test_utils.py b/test/unit/common/test_utils.py index 73b1390ef9..2f4e7319a4 100644 --- a/test/unit/common/test_utils.py +++ b/test/unit/common/test_utils.py @@ -1172,6 +1172,43 @@ log_name = %(yarr)s''' finally: utils._sys_fallocate = orig__sys_fallocate + def test_generate_trans_id(self): + fake_time = 1366428370.5163341 + with patch.object(utils.time, 'time', return_value=fake_time): + trans_id = utils.generate_trans_id('') + self.assertEquals(len(trans_id), 34) + self.assertEquals(trans_id[:2], 'tx') + self.assertEquals(trans_id[23], '-') + self.assertEquals(int(trans_id[24:], 16), int(fake_time)) + with patch.object(utils.time, 'time', return_value=fake_time): + trans_id = utils.generate_trans_id('-suffix') + self.assertEquals(len(trans_id), 41) + self.assertEquals(trans_id[:2], 'tx') + self.assertEquals(trans_id[34:], '-suffix') + self.assertEquals(trans_id[23], '-') + self.assertEquals(int(trans_id[24:34], 16), int(fake_time)) + + def test_get_trans_id_time(self): + ts = utils.get_trans_id_time('tx8c8bc884cdaf499bb29429aa9c46946e') + self.assertEquals(ts, None) + ts = utils.get_trans_id_time('tx1df4ff4f55ea45f7b2ec2-0051720c06') + self.assertEquals(ts, 1366428678) + self.assertEquals( + time.asctime(time.gmtime(ts)) + ' UTC', + 'Sat Apr 20 03:31:18 2013 UTC') + ts = utils.get_trans_id_time( + 'tx1df4ff4f55ea45f7b2ec2-0051720c06-suffix') + self.assertEquals(ts, 1366428678) + self.assertEquals( + time.asctime(time.gmtime(ts)) + ' UTC', + 'Sat Apr 20 03:31:18 2013 UTC') + ts = utils.get_trans_id_time('') + self.assertEquals(ts, None) + ts = utils.get_trans_id_time('garbage') + self.assertEquals(ts, None) + ts = utils.get_trans_id_time('tx1df4ff4f55ea45f7b2ec2-almostright') + self.assertEquals(ts, None) + class TestStatsdLogging(unittest.TestCase): def test_get_logger_statsd_client_not_specified(self):