Commits

Jean-Tiare LE BIGOT  committed 54eca8d

centralize logging for both routers

  • Participants
  • Parent commits 61e0d77

Comments (0)

Files changed (5)

File ddbmock/router/__init__.py

 # -*- coding: utf-8 -*-
 
 from importlib import import_module
+from ddbmock.utils import req_logger
 from ddbmock.errors import InternalFailure
 from ddbmock.validators import dynamodb_api_validate
-import re
+import re, itertools
+
+request_counter = itertools.count()  # atomic counter
 
 first_cap_re = re.compile('(.)([A-Z][a-z]+)')
 all_cap_re = re.compile('([a-z0-9])([A-Z])')
 
+
 def action_to_route(name):
     s1 = first_cap_re.sub(r'\1_\2', name)
     return all_cap_re.sub(r'\1_\2', s1).lower()
 
 def router(action, post):
+    request_id = str(request_counter.next())  # register the id in the post for it to be accessible in case of exception
+    post['request_id'] = request_id
+    req_logger.debug("request_id=%s action=%s body=%s", request_id, action, post)
+
     # Find route
     try:
         target = action_to_route(action)
         mod = import_module('ddbmock.operations.{}'.format(target))
         func = getattr(mod, target)
     except ImportError:
+        req_logger.error('request_id=%s action=%s No such action', request_id, action)
         raise InternalFailure("Method: {} does not exist".format(action))
 
     # Validate the input
-    post = dynamodb_api_validate(target, post)
+    try:
+        post = dynamodb_api_validate(target, post)
+    except Exception as e:
+        req_logger.error('request_id=%s action=%s exception=%s body=%s', request_id, action, type(e).__name__, str(e.args))
+        raise
 
     # Run request and translate engine errors to DynamoDB errors
     try:
-        return func(post)
+        answer = func(post)
+        #req_logger.debug("request_id=%s action=%s answer=%s", post['request_id'], action, answer)
+        return answer
     except (TypeError, ValueError, KeyError) as e:
+        req_logger.error('request_id=%s action=%s exception=%s body=%s', request_id, action, type(e).__name__, str(e.args))
         raise InternalFailure("{}: {}".format(type(e).__name__, str(e.args)))

File ddbmock/router/boto.py

 # boto entry point: semantic name
 from __future__ import absolute_import
 
-import json, time, itertools, boto
+import json, time, boto
 
 from ddbmock.router import router
 from ddbmock.errors import ValidationException, ConditionalCheckFailedException, DDBError
     else:
         return DynamoDBResponseError(err.status, err.status_str, err.to_dict())
 
-request_counter = itertools.count()
 
 # Boto lib version entry point
 def boto_router(self, action, body='', object_hook=None):
     skips the authentication part. The external behavior is strictly compatible"""
     target = '%s_%s.%s' % (self.ServiceName, self.Version, action)
     start = time.time()
-    request_id = request_counter.next()
 
-    boto.log.info("ddbmock: '%s' request (%s) => %s", action, request_id, body)
+    post = json.loads(body)
 
     try:
-        ret = router(action, json.loads(body))
+        ret = router(action, post)
     except DDBError as e:
         raise _ddbmock_exception_to_boto_exception(e)
     finally:
-        boto.log.debug('RequestId: %s', request_id)
+        boto.log.debug('RequestId: %s', post['request_id'])
         elapsed = (time.time() - start) * 1000
-        boto.perflog.info('dynamodb %s: id=%s time=%sms',
-                          target, request_id, int(elapsed))
-
-    # Not in the finally block because, in case of error, they are already translated
-    boto.log.info("ddbmock: '%s' answer (%s) => %s", action, request_id, ret)
+        boto.perflog.info('dynamodb %s: id=%s time=%sms', target, post['request_id'], int(elapsed))
 
     # FIXME: dump followed by load... can be better...
     ret = json.dumps(ret)

File ddbmock/router/pyramid.py

     target = request.headers.get('x-amz-target')
     action = target.split('.', 2)[1] if target is not None else ""
 
+    post = request.json
+
     # do the job
     try:
-        body = router(action, request.json)
+        body = router(action, post)
         status = '200 OK'
     except DDBError as e:
         body = e.to_dict()
     response.body = json.dumps(body)
     response.status = status
     response.content_type = 'application/x-amz-json-1.0'
+    response.headers['x-amzn-RequestId'] = post['request_id']  # added by router
 
     # done
     return response

File ddbmock/utils/__init__.py

     'write': {},
 }
 
+req_logger = logging.getLogger("Request logger")
+req_logger.addHandler(logging.NullHandler())
+
 tp_logger = logging.getLogger("Throughput logger")
 tp_logger.addHandler(logging.NullHandler())
 

File ddbmock/validators/__init__.py

     except (ImportError, AttributeError):
         return post  # Fixme: should log
 
+    # ignore the 'request_id' key but propagate it
+    schema['request_id'] = str
+
     try:
         validate = Schema(schema, required=True)
         return validate(post)