BD-294 - Dev logger refactor

perimeterx/px_blocker.py

@@ -35,18 +35,18 @@ def handle_blocking(self, ctx, config):
         headers = {'Content-Type': content_type}
 
         if action is px_constants.ACTION_CHALLENGE:
-            logger.debug('Challenge page is served')
+            logger.debug('Enforcing action: Challenge page is served')
             blocking_props = ctx.block_action_data
             blocking_response = blocking_props
 
         elif action is px_constants.ACTION_RATELIMIT:
-            logger.debug('Rate limit page is served')
+            logger.debug('Enforcing action: Rate limit page is served')
             blocking_props = None
             blocking_response = self.ratelimit_rendered_page
             status = '429 Too Many Requests'
 
         else:  # block
-            logger.debug('Block page is served')
+            logger.debug('Enforcing action: Block page is served')
             blocking_props = self.prepare_properties(ctx, config)
             blocking_response = self.mustache_renderer.render(px_template.get_template(px_constants.BLOCK_TEMPLATE),
                                                               blocking_props)
@@ -63,6 +63,7 @@ def handle_blocking(self, ctx, config):
             return page_response, headers, status
 
         if is_json_response:
+            logger.debug('Serving advanced blocking response')
             blocking_response = json.dumps(blocking_props)
 
         blocking_response = str(blocking_response)

perimeterx/px_cookie_validator.py

@@ -19,7 +19,7 @@ def verify(ctx, config):
     logger = config.logger
     try:
         if not ctx.px_cookies.keys():
-            logger.debug('No risk cookie on the request')
+            logger.debug('Cookie is missing')
             ctx.s2s_call_reason = 'no_cookie'
             return False
 
@@ -46,7 +46,7 @@ def verify(ctx, config):
 
         if not px_cookie.deserialize():
             cookie = px_cookie._hmac + ":" + px_cookie._raw_cookie
-            logger.error('Cookie decryption failed, value: {}'.format(cookie))
+            logger.debug('Cookie decryption failed, value: {}'.format(cookie))
             ctx.px_cookie_raw = cookie_version + "=" + cookie
             ctx.s2s_call_reason = 'cookie_decryption_failed'
             return False
@@ -67,7 +67,7 @@ def verify(ctx, config):
 
         if px_cookie.is_cookie_expired():
             ctx.s2s_call_reason = 'cookie_expired'
-            msg = 'Cookie TTL expired, value: {}, age: {}'
+            msg = 'Cookie TTL is expired, value: {}, age: {}'
             logger.debug(msg.format(px_cookie.decoded_cookie, px_cookie.get_age()))
             return False
 
@@ -86,7 +86,7 @@ def verify(ctx, config):
         return True
     except Exception, err:
         traceback.print_exc()
-        logger.debug('Unexpected exception while evaluating Risk cookie. Error: {}'.format(err))
+        logger.error('Unexpected exception while evaluating Risk cookie. Error: {}'.format(err))
         ctx.px_cookie_raw = px_cookie._raw_cookie
         ctx.s2s_call_reason = 'cookie_decryption_failed'
         return False

perimeterx/px_logger.py

@@ -1,11 +1,21 @@
+import logging
+
 class Logger(object):
     def __init__(self, debug, app_id):
         self.debug_mode = debug
         self.app_id = app_id
 
+        # Setup logger
+        self.logger = logging.getLogger(__name__)
+        handler = logging.StreamHandler()
+        formatter = logging.Formatter('[PerimeterX %(levelname)s][{}]: %(message)s'.format(self.app_id))
+        handler.setFormatter(formatter)
+        self.logger.addHandler(handler)
+        self.logger.setLevel(logging.DEBUG)
+
     def debug(self, message):
-        if self.debug_mode:
-            print '[PerimeterX DEBUG][{}]: '.format(self.app_id) + message
+		if self.debug_mode:
+			self.logger.debug(message)
 
     def error(self, message):
-        print '[PerimeterX ERROR][{}]: '.format(self.app_id) + message
+        self.logger.error(message)

perimeterx/px_original_token_validator.py

@@ -17,7 +17,7 @@ def verify(ctx, config):
         cookie_version, px_cookie = px_cookie_builder.build_px_cookie({version: no_version_token}, '')
 
         if not px_cookie.deserialize():
-            logger.error('Original token decryption failed, value: {}'.format(px_cookie.raw_cookie))
+            logger.debug('Original token decryption failed, value: {}'.format(px_cookie.raw_cookie))
             ctx.original_token_error = 'decryption_failed'
             return False