Merge pull request #108 from corydolphin/patch/logging-improvements

Use hierarchical logging, reduce logging verbosity
corydolphin · Mar 6, 2015 · 7bcbe14 · 7bcbe14
2 parents ea0559c + b88b699
commit 7bcbe14
Show file tree

Hide file tree

Showing 6 changed files with 66 additions and 155 deletions.
diff --git a/README.md b/README.md
@@ -59,12 +59,12 @@ def helloWorld():
 
 #### Logging
 
-Flask-Cors uses standard Python logging, using the module name 'Flask-Cors'. You can read more about logging from [Flask's documentation](http://flask.pocoo.org/docs/0.10/errorhandling/).
+Flask-Cors uses standard Python logging, using the logger name '`app.logger_name`.cors'. The app's logger name attribute is usually the same as the name of the app. You can read more about logging from [Flask's documentation](http://flask.pocoo.org/docs/0.10/errorhandling/).
 
 ```python
 import logging
 # make your awesome app
-logging.basicConfig(level=logging.DEBUG)
+logging.basicConfig(level=logging.INFO)
 ```
 
 ## Documentation
@@ -133,7 +133,7 @@ The application-wide configuration options are identical to the keyword argument
 
 * CORS_ORIGINS
 * CORS_METHODS
-* CORS_HEADERS
+* CORS_ALLOW_HEADERS
 * CORS_EXPOSE_HEADERS
 * CORS_ALWAYS_SEND
 * CORS_MAX_AGE

diff --git a/README.rst b/README.rst
@@ -81,15 +81,17 @@ CORS on a given route.
 Logging
 ^^^^^^^
 
-Flask-Cors uses standard Python logging, using the module name
-'Flask-Cors'. You can read more about logging from `Flask's
+Flask-Cors uses standard Python logging, using the logger name
+'``app.logger_name``.cors'. The app's logger name attribute is usually
+the same as the name of the app. You can read more about logging from
+`Flask's
 documentation <http://flask.pocoo.org/docs/0.10/errorhandling/>`__.
 
 .. code:: python
 
     import logging
     # make your awesome app
-    logging.basicConfig(level=logging.DEBUG)
+    logging.basicConfig(level=logging.INFO)
 
 Documentation
 -------------

diff --git a/docs/index.rst b/docs/index.rst
@@ -81,134 +81,18 @@ CORS on a given route.
 Logging
 ^^^^^^^
 
-Flask-Cors uses standard Python logging, using the module name
-'Flask-Cors'. You can read more about logging from `Flask's
+Flask-Cors uses standard Python logging, using the logger name
+'``app.logger_name``.cors'. The app's logger name attribute is usually
+the same as the name of the app. You can read more about logging from
+`Flask's
 documentation <http://flask.pocoo.org/docs/0.10/errorhandling/>`__.
 
 .. code:: python
 
     import logging
     # make your awesome app
-    logging.basicConfig(level=logging.DEBUG)
+    logging.basicConfig(level=logging.INFO)
 
-Documentation
--------------
-
-For a full list of options, please see the full
-`documentation <http://flask-cors.readthedocs.org/en/latest/>`__
-
-Options
-~~~~~~~
-
-origins
-^^^^^^^
-
-    Default : '\*'
-
-The origin, or list of origins to allow requests from. The origin(s) may
-be regular expressions, exact origins, or else an asterisk.
-
-methods
-^^^^^^^
-
-    Default : [GET, HEAD, POST, OPTIONS, PUT, PATCH, DELETE]
-
-The method or list of methods which the allowed origins are allowed to
-access for non-simple requests.
-
-expose\_headers
-^^^^^^^^^^^^^^^
-
-    Default : None
-
-The header or list of headers which are safe to expose to the API of a
-CORS API specification
-
-allow\_headers
-^^^^^^^^^^^^^^
-
-    Default : None
-
-The header or list of header field names which can be used when this
-resource is accessed by allowed origins.
-
-supports\_credentials
-^^^^^^^^^^^^^^^^^^^^^
-
-    Default : False
-
-Allows users to make authenticated requests. If true, injects the
-``Access-Control-Allow-Credentials`` header in responses.
-
-max\_age
-^^^^^^^^
-
-    Default : None
-
-The maximum time for which this CORS request maybe cached. This value is
-set as the ``Access-Control-Max-Age`` header.
-
-send\_wildcard
-^^^^^^^^^^^^^^
-
-    Default : True
-
-If True, and the origins parameter is ``*``, a wildcard
-``Access-Control-Allow-Origin`` header is sent, rather than the
-request's ``Origin`` header.
-
-always\_send
-^^^^^^^^^^^^
-
-    Default : True
-
-If True, CORS headers are sent even if there is no ``Origin`` in the
-request's headers.
-
-automatic\_options
-^^^^^^^^^^^^^^^^^^
-
-    Default : True
-
-If True, CORS headers will be returned for OPTIONS requests. For use
-with cross domain POST requests which preflight OPTIONS requests, you
-will need to specifically allow the Content-Type header. \*\* Only
-applicable for use in the decorator\*\*
-
-vary\_header
-^^^^^^^^^^^^
-
-    Default : True
-
-If True, the header Vary: Origin will be returned as per suggestion by
-the W3 implementation guidelines. Setting this header when the
-``Access-Control-Allow-Origin`` is dynamically generated (e.g. when
-there is more than one allowed origin, and an Origin than '\*' is
-returned) informs CDNs and other caches that the CORS headers are
-dynamic, and cannot be re-used. If False, the Vary header will never be
-injected or altered.
-
-Application-wide options
-~~~~~~~~~~~~~~~~~~~~~~~~
-
-Alternatively, you can set all parameters **except automatic\_options**
-in an app's config object. Setting these at the application level
-effectively changes the default value for your application, while still
-allowing you to override it on a per-resource basis, either via the CORS
-Flask-Extension and regular expressions, or via the ``@cross_origin()``
-decorator.
-
-The application-wide configuration options are identical to the keyword
-arguments to ``cross_origin``, creatively prefixed with ``CORS_``
-
--  CORS\_ORIGINS
--  CORS\_METHODS
--  CORS\_HEADERS
--  CORS\_EXPOSE\_HEADERS
--  CORS\_ALWAYS\_SEND
--  CORS\_MAX\_AGE
--  CORS\_SEND\_WILDCARD
--  CORS\_ALWAYS\_SEND
 
 Using JSON with CORS
 ~~~~~~~~~~~~~~~~~~~~

diff --git a/examples/app_based_example.py b/examples/app_based_example.py
@@ -20,8 +20,8 @@
     from flask.ext.cors import CORS
 
 
-app = Flask(__name__)
-logging.basicConfig(level=logging.DEBUG)
+app = Flask('FlaskCorsAppBasedExample')
+logging.basicConfig(level=logging.INFO)
 
 # One of the simplest configurations. Exposes all resources matching /api/* to
 # CORS and allows the Content-Type header, which is necessary to POST JSON

diff --git a/examples/view_based_example.py b/examples/view_based_example.py
@@ -21,9 +21,8 @@
     from flask.ext.cors import cross_origin
 
 
-app = Flask(__name__)
-logging.basicConfig(level=logging.DEBUG)
-
+app = Flask('FlaskCorsViewBasedExample')
+logging.basicConfig(level=logging.INFO)
 
 @app.route("/", methods=['GET'])
 @cross_origin()

diff --git a/flask_cors/__init__.py b/flask_cors/__init__.py
@@ -8,23 +8,27 @@
     :copyright: (c) 2014 by Cory Dolphin.
     :license: MIT, see LICENSE for more details.
 """
-
+import re
 import logging
 import collections
 from datetime import timedelta
-import re
 from functools import update_wrapper
-from flask import make_response, request, current_app
 from six import string_types
+from flask import make_response, request, current_app
+try:
+    from flask import _app_ctx_stack as stack
+except ImportError:
+    from flask import _request_ctx_stack as stack
+
 from ._version import __version__
 
-logger = logging.getLogger('Flask-Cors')
+
+# Compatibility with old Pythons!
 if not hasattr(logging, 'NullHandler'):
     class NullHandler(logging.Handler):
         def emit(self, record):
             pass
     logging.NullHandler = NullHandler
-logger.addHandler(logging.NullHandler())
 
 # Common string constants
 ACL_ORIGIN = 'Access-Control-Allow-Origin'
@@ -159,8 +163,8 @@ def wrapped_function(*args, **kwargs):
             options.update(_get_app_kwarg_dict())
             options.update(_options)
             _serialize_options(options)
-            logger.debug("Request to '%s' is enabled for CORS with options:%s",
-                         request.path, options)
+
+            getLogger().debug("Using computed options %s", options)
 
             if options.get('automatic_options') and request.method == 'OPTIONS':
                 resp = current_app.make_default_options_response()
@@ -243,8 +247,15 @@ def init_app(self, app, **kwargs):
 
         _intercept_exceptions = options.get('intercept_exceptions', True)
         resources = _parse_resources(options.get('resources', [r'/*']))
-        logger.info("Configuring CORS for app:'%s' with resources:%s", \
-                     app.name, resources)
+        resources_human = dict(
+            map(
+                lambda r: (_get_regexp_pattern(r[0]), r[1]),
+                resources
+            )
+        )
+
+        getLogger(app).info("Configuring CORS with resources and options%s", resources_human)
+
 
         def cors_after_request(resp):
             '''
@@ -253,20 +264,20 @@ def cors_after_request(resp):
             '''
             # If CORS headers are set in a view decorator, pass
             if resp.headers.get(ACL_ORIGIN):
-                logger.debug('CORS have been already evaluated, skipping')
+                getLogger().debug('CORS have been already evaluated, skipping')
                 return resp
 
             for res_regex, res_options in resources:
                 if _try_match(res_regex, request.path):
                     _options = options.copy()
                     _options.update(res_options)
                     _serialize_options(_options)
-                    logger.debug("Request to '%s' matches CORS resource '%s'. Using options: %s",
+                    getLogger().debug("Request to '%s' matches CORS resource '%s'. Using options: %s",
                         request.path, _get_regexp_pattern(res_regex), _options)
                     _set_cors_headers(resp, _options)
                     break
             else:
-                logger.debug('No CORS rule matches')
+                getLogger().debug('No CORS rule matches')
             return resp
 
         app.after_request(cors_after_request)
@@ -336,11 +347,11 @@ def _get_cors_origin(options, request_origin):
     # If the Origin header is not present terminate this set of steps.
     # The request is outside the scope of this specification.-- W3Spec
     if request_origin:
-        logger.debug("CORS request received with 'Origin' %s", request_origin)
+        getLogger().debug("CORS request received with 'Origin' %s", request_origin)
 
         # If the allowed origins is an asterisk or 'wildcard', always match
         if wildcard:
-            logger.debug("Allowed origins are set to '*', assuming valid request")
+            getLogger().debug("Allowed origins are set to '*', assuming valid request")
             if options.get('send_wildcard'):
                 return '*'
             else:
@@ -349,13 +360,13 @@ def _get_cors_origin(options, request_origin):
         # If the value of the Origin header is a case-sensitive match
         # for any of the values in list of origins
         elif any(_try_match(pattern, request_origin) for pattern in origins):
-            logger.debug("Given origin matches set of allowed origins")
+            getLogger().debug("Given origin matches set of allowed origins")
             # Add a single Access-Control-Allow-Origin header, with either
             # the value of the Origin header or the string "*" as value.
             # -- W3Spec
             return request_origin
         else:
-            logger.debug("Given origin does not match any of allowed origins: %s",
+            getLogger().debug("Given origin does not match any of allowed origins: %s",
                          map(_get_regexp_pattern, origins))
             return None
 
@@ -366,22 +377,28 @@ def _get_cors_origin(options, request_origin):
     # This will only be exceuted it there is no Origin in the request, in which
     # case, why bother with CORS?
     elif options.get('always_send') and options.get('origins_str'):
-        logger.debug("No 'Origin' header in request, skipping")
+        getLogger().debug("No 'Origin' header in request, skipping")
         return options.get('origins_str')
     # Terminate these steps, return the original request untouched.
     else:
-        logger.debug("'Origin' header was not send, which means CORS was not requested, skipping")
+        getLogger().debug("'Origin' header was not send, which means CORS was not requested, skipping")
         return None
 
 
 def _get_cors_headers(options, request_headers, request_method,
                       response_headers=None):
-    headers = dict(response_headers or {})  # copy dict
     origin_to_set = _get_cors_origin(options, request_headers.get('Origin'))
 
+    if 'Vary' in response_headers:
+        headers = {'Vary': response_headers.get('Vary')}
+    else:
+        headers = {}
+
+
+
     if origin_to_set is None:  # CORS is not enabled for this route
         return headers
-    logger.info("CORS request from Origin:%s, setting %s:%s",
+    getLogger().info("CORS request from Origin:%s, setting %s:%s",
                 request_headers.get('Origin'), ACL_ORIGIN, origin_to_set)
 
     headers[ACL_ORIGIN] = origin_to_set
@@ -404,7 +421,7 @@ def _get_cors_headers(options, request_headers, request_method,
 
     # http://www.w3.org/TR/cors/#resource-implementation
     if headers[ACL_ORIGIN] != '*' and options.get('vary_header'):
-        vary = ['Origin', headers.get('Vary', None)]
+        vary = ['Origin', headers.get('Vary')]
         headers['Vary'] = ', '. join(v for v in vary if v is not None)
 
     return dict((k, v) for k, v in headers.items() if v is not None)
@@ -421,14 +438,14 @@ def _set_cors_headers(resp, options):
 
     # If CORS has already been evaluated via the decorator, skip
     if hasattr(resp, FLASK_CORS_EVALUATED):
-        logger.debug('CORS have been already evaluated, skipping')
+        getLogger().debug('CORS have been already evaluated, skipping')
         return resp
 
     headers_to_set = _get_cors_headers(options,
                                        request.headers,
                                        request.method,
                                        resp.headers)
-    logger.debug('Settings CORS headers: %s', str(headers_to_set))
+    getLogger().debug('Settings CORS headers: %s', str(headers_to_set))
 
     for k, v in headers_to_set.items():
         resp.headers[k] = v
@@ -544,3 +561,12 @@ def _serialize_options(options):
 
     if isinstance(options.get('max_age'), timedelta):
         options['max_age'] = str(int(options['max_age'].total_seconds()))
+
+
+def getLogger(app=None):
+    if stack.top is not None: # we are in the context of a request
+        return logging.getLogger("%s.cors" % current_app.logger_name)
+    elif app is not None: # For use init method, when an app is known, but there is no context
+        return logging.getLogger("%s.cors" % app.logger_name)
+    else:
+        return logging.getLogger("flask.ext.cors")