Features

  - The ``BFG_DEBUG_AUTHORIZATION`` envvar and the
    ``debug_authorization`` config file value now only imply debugging
    of view-invoked security checks.  Previously, information was
    printed for every call to ``has_permission`` as well, which made
    output confusing.  To debug ``has_permission`` checks and other
    manual permission checks, use the debugger and print statements in
    your own code.

  - Authorization debugging info is now only present in the HTTP
    response body oif ``debug_authorization`` is true.

  - The format of authorization debug messages was improved.

  - A new ``BFG_DEBUG_NOTFOUND`` envvar was added and a symmetric
    ``debug_notfound`` config file value was added.  When either is
    true, and a NotFound response is returned by the BFG router
    (because a view could not be found), debugging information is
    printed to stderr.  When this value is set true, the body of
    HTTPNotFound responses will also contain the same debugging
    information.

  - ``Allowed`` and ``Denied`` responses from the security machinery
    are now specialized into two types: ACL types, and non-ACL types.
    The ACL-related responses are instances of
    ``repoze.bfg.security.ACLAllowed`` and
    ``repoze.bfg.security.ACLDenied``.  The non-ACL-related responses
    are ``repoze.bfg.security.Allowed`` and
    ``repoze.bfg.security.Denied``.  The allowed-type responses
    continue to evaluate equal to things that themselves evaluate
    equal to the ``True`` boolean, while the denied-type responses
    continue to evaluate equal to things that themselves evaluate
    equal to the ``False`` boolean.  The only difference between the
    two types is the information attached to them for debugging
    purposes.

  - Added a new ``BFG_DEBUG_ALL`` envvar and a symmetric ``debug_all``
    config file value.  When either is true, all other debug-related
    flags are set true unconditionally (e.g. ``debug_notfound`` and
    ``debug_authorization``).

  Documentation

  - Added info about debug flag changes.

  - Added a section to the security chapter named "Debugging
    Imperative Authorization Failures" (for e.g. ``has_permssion``).

1 files changed, 37 insertions, 7 deletions

diff --git a/repoze/bfg/router.py b/repoze/bfg/router.py
index 28cb319cb..d51d07dda 100644
--- a/repoze/bfg/router.py
+++ b/repoze/bfg/router.py
@@ -1,4 +1,7 @@
+from cgi import escape
+
 from zope.component import getAdapter
+from zope.component import queryUtility
 from zope.component.event import dispatch
 from zope.interface import directlyProvides
 from zope.interface import implements
@@ -11,9 +14,11 @@ from repoze.bfg.events import NewRequest
 from repoze.bfg.events import NewResponse
 from repoze.bfg.events import WSGIApplicationCreatedEvent
 
+from repoze.bfg.interfaces import ILogger
 from repoze.bfg.interfaces import ITraverserFactory
 from repoze.bfg.interfaces import IRequest
 from repoze.bfg.interfaces import IRouter
+from repoze.bfg.interfaces import ISettings
 
 from repoze.bfg.registry import registry_manager
 from repoze.bfg.registry import makeRegistry
@@ -21,6 +26,7 @@ from repoze.bfg.registry import makeRegistry
 from repoze.bfg.security import Unauthorized
 
 from repoze.bfg.view import render_view_to_response
+from repoze.bfg.view import view_execution_permitted
 
 _marker = ()
 
@@ -41,22 +47,46 @@ class Router(object):
         dispatch(NewRequest(request))
         root = self.root_policy(environ)
         traverser = getAdapter(root, ITraverserFactory)
+        settings = queryUtility(ISettings)
         context, name, subpath = traverser(environ)
 
         request.context = context
         request.view_name = name
         request.subpath = subpath
 
-        try:
-            response = render_view_to_response(context, request, name,
-                                               secure=True)
-        except Unauthorized, why:
-            app = HTTPUnauthorized()
-            app.explanation = str(why)
+        permitted = view_execution_permitted(context, request, name)
+        debug_authorization = settings and settings.debug_authorization
+
+        if debug_authorization:
+            logger = queryUtility(ILogger, 'repoze.bfg.debug')
+            logger and logger.debug(
+                'debug_authorization of url %s (view name %r against context '
+                '%r): %s' % (request.url, name, context, permitted.msg)
+                )
+        if not permitted:
+            if debug_authorization:
+                msg = permitted.msg
+            else:
+                msg = 'Unauthorized: failed security policy check'
+            app = HTTPUnauthorized(escape(msg))
             return app(environ, start_response)
+            
+        response = render_view_to_response(context, request, name,
+                                           secure=False)
 
         if response is None:
-            app = HTTPNotFound(request.url)
+            debug_notfound = settings and settings.debug_notfound
+            if debug_notfound:
+                logger = queryUtility(ILogger, 'repoze.bfg.debug')
+                msg = (
+                    'debug_notfound of url %s; path_info: %r, context: %r, '
+                    'view_name: %r, subpath: %r' % (
+                    request.url, request.path_info, context, name, subpath)
+                    )
+                logger and logger.debug(msg)
+            else:
+                msg = request.url
+            app = HTTPNotFound(escape(msg))
             return app(environ, start_response)
 
         dispatch(NewResponse(response))