Docs

   - An "Environment and Configuration" chapter was added to the narrative 
     portion of the documentation.

  Features

   - Ensure bfg doesn't generate warnings when running under Python
     2.6.

   - The environment variable ``BFG_RELOAD_TEMPLATES`` is now available
     (serves the same purpose as ``reload_templates`` in the config file).

   - A new configuration file option ``debug_authorization`` was added.
     This turns on printing of security authorization debug statements
     to ``sys.stderr``.  The ``BFG_DEBUG_AUTHORIZATION`` environment
     variable was also added; this performs the same duty.

  Bug Fixes

   - The environment variable ``BFG_SECURITY_DEBUG`` did not always work.
     It has been renamed to ``BFG_DEBUG_AUTHORIZATION`` and fixed.

  Deprecations

   - A deprecation warning is now issued when old API names from the
     ``repoze.bfg.templates`` module are imported.

  Backwards incompatibilities

   - The ``BFG_SECURITY_DEBUG`` environment variable was renamed to
     ``BFG_DEBUG_AUTHORIZATION``.

3 files changed, 85 insertions, 30 deletions

diff --git a/repoze/bfg/tests/test_log.py b/repoze/bfg/tests/test_log.py
new file mode 100644
index 000000000..4cc8d12a0
--- /dev/null
+++ b/repoze/bfg/tests/test_log.py
@@ -0,0 +1,16 @@
+import unittest
+
+class TestFunctions(unittest.TestCase):
+    def test_make_stream_logger(self):
+        from repoze.bfg.log import make_stream_logger
+        import logging
+        import sys
+        logger = make_stream_logger('foo', sys.stderr, levelname='DEBUG',
+                                    fmt='%(message)s')
+        self.assertEqual(logger.name, 'foo')
+        self.assertEqual(logger.handlers[0].stream, sys.stderr)
+        self.assertEqual(logger.handlers[0].formatter._fmt, '%(message)s')
+        self.assertEqual(logger.level, logging.DEBUG)
+        
+        
+
diff --git a/repoze/bfg/tests/test_registry.py b/repoze/bfg/tests/test_registry.py
index efc99b41a..d2e6b4caf 100644
--- a/repoze/bfg/tests/test_registry.py
+++ b/repoze/bfg/tests/test_registry.py
@@ -23,7 +23,8 @@ class TestMakeRegistry(unittest.TestCase, PlacelessSetup):
             old = repoze.bfg.registry.setRegistryManager(dummyregmgr)
             registry = makeRegistry('configure.zcml',
                                     fixtureapp,
-                                    options={'reload_templates':True},
+                                    options={'reload_templates':True,
+                                             'debug_authorization':True},
                                     lock=dummylock)
             from zope.component.registry import Components
             self.failUnless(isinstance(registry, Components))
@@ -32,8 +33,12 @@ class TestMakeRegistry(unittest.TestCase, PlacelessSetup):
             self.assertEqual(dummyregmgr.registry, registry)
             from zope.component import getUtility
             from repoze.bfg.interfaces import ISettings
+            from repoze.bfg.interfaces import ILogger
             settings = getUtility(ISettings)
+            logger = getUtility(ILogger, name='repoze.bfg.authdebug')
+            self.assertEqual(logger.name, 'repoze.bfg.authdebug')
             self.assertEqual(settings.reload_templates, True)
+            self.assertEqual(settings.debug_authorization, True)
         finally:
             repoze.bfg.registry.setRegistryManager(old)
 
@@ -52,6 +57,27 @@ class TestGetOptions(unittest.TestCase):
         self.assertEqual(result['reload_templates'], True)
         result = get_options({'reload_templates':'1'})
         self.assertEqual(result['reload_templates'], True)
+        result = get_options({}, {'BFG_RELOAD_TEMPLATES':'1'})
+        self.assertEqual(result['reload_templates'], True)
+        result = get_options({'reload_templates':'false'},
+                             {'BFG_RELOAD_TEMPLATES':'1'})
+        self.assertEqual(result['reload_templates'], True)
+
+    def test_debug_authorization(self):
+        get_options = self._getFUT()
+        result = get_options({})
+        self.assertEqual(result['debug_authorization'], False)
+        result = get_options({'debug_authorization':'false'})
+        self.assertEqual(result['debug_authorization'], False)
+        result = get_options({'debug_authorization':'t'})
+        self.assertEqual(result['debug_authorization'], True)
+        result = get_options({'debug_authorization':'1'})
+        self.assertEqual(result['debug_authorization'], True)
+        result = get_options({}, {'BFG_DEBUG_AUTHORIZATION':'1'})
+        self.assertEqual(result['debug_authorization'], True)
+        result = get_options({'debug_authorization':'false'},
+                             {'BFG_DEBUG_AUTHORIZATION':'1'})
+        self.assertEqual(result['debug_authorization'], True)
 
 class TestThreadLocalRegistryManager(unittest.TestCase, PlacelessSetup):
     def setUp(self):
diff --git a/repoze/bfg/tests/test_security.py b/repoze/bfg/tests/test_security.py
index 98750c728..4a1511c50 100644
--- a/repoze/bfg/tests/test_security.py
+++ b/repoze/bfg/tests/test_security.py
@@ -219,6 +219,12 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         klass = self._getTargetClass()
         return klass(*arg, **kw)
 
+    def _registerLogger(self, logger):
+        import zope.component
+        gsm = zope.component.getGlobalSiteManager()
+        from repoze.bfg.interfaces import ILogger
+        gsm.registerUtility(logger, ILogger, name='repoze.bfg.authdebug')
+
     def setUp(self):
         PlacelessSetup.setUp(self)
 
@@ -233,14 +239,12 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
     def test_instance_implements_ISecurityPolicy(self):
         from zope.interface.verify import verifyObject
         from repoze.bfg.interfaces import ISecurityPolicy
-        logger = DummyLogger()
-        verifyObject(ISecurityPolicy, self._makeOne(logger, lambda *arg: None))
+        verifyObject(ISecurityPolicy, self._makeOne(lambda *arg: None))
 
     def test_permits_no_principals_no_acl_info_on_context(self):
         context = DummyContext()
         request = DummyRequest({})
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         authorizer_factory = make_authorizer_factory(None)
         policy.authorizer_factory = authorizer_factory
         result = policy.permits(context, request, 'view')
@@ -254,8 +258,7 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         context = DummyContext()
         context.__acl__ = []
         request = DummyRequest({})
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         authorizer_factory = make_authorizer_factory(None)
         policy.authorizer_factory = authorizer_factory
         result = policy.permits(context, request, 'view')
@@ -274,8 +277,7 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         context2.__parent__ = context
         context.__acl__ = []
         request = DummyRequest({})
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         authorizer_factory = make_authorizer_factory(None)
         policy.authorizer_factory = authorizer_factory
         result = policy.permits(context, request, 'view')
@@ -293,8 +295,7 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         context2.__name__ = 'context2'
         context2.__parent__ = context
         request = DummyRequest({})
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         authorizer_factory = make_authorizer_factory(context)
         policy.authorizer_factory = authorizer_factory
         result = policy.permits(context, request, 'view')
@@ -303,15 +304,34 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         self.assertEqual(authorizer_factory.principals, (Everyone,))
         self.assertEqual(authorizer_factory.permission, 'view')
         self.assertEqual(authorizer_factory.context, context)
-    
+
+    def test_permits_with_logger(self):
+        logger = DummyLogger()
+        self._registerLogger(logger)
+        context = DummyContext()
+        request = DummyRequest({})
+        policy = self._makeOne(lambda *arg: None)
+        authorizer_factory = make_authorizer_factory(context)
+        policy.authorizer_factory = authorizer_factory
+        policy.permits(context, request, 'view')
+        self.assertEqual(authorizer_factory.logger, logger)
+
+    def test_permits_no_logger(self):
+        context = DummyContext()
+        request = DummyRequest({})
+        policy = self._makeOne(lambda *arg: None)
+        authorizer_factory = make_authorizer_factory(context)
+        policy.authorizer_factory = authorizer_factory
+        policy.permits(context, request, 'view')
+        self.assertEqual(authorizer_factory.logger, None)
+
     def test_principals_allowed_by_permission_direct(self):
         from repoze.bfg.security import Allow
         context = DummyContext()
         acl = [ (Allow, 'chrism', ('read', 'write')),
                 (Allow, 'other', ('read',)) ]
         context.__acl__ = acl
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         result = policy.principals_allowed_by_permission(context, 'read')
         self.assertEqual(result, ['chrism', 'other'])
 
@@ -326,14 +346,12 @@ class TestACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         inter = DummyContext()
         inter.__name__ = None
         inter.__parent__ = context
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         result = policy.principals_allowed_by_permission(inter, 'read')
         self.assertEqual(result, ['chrism', 'other'])
 
     def test_principals_allowed_by_permission_no_acls(self):
-        logger = DummyLogger()
-        policy = self._makeOne(logger, lambda *arg: None)
+        policy = self._makeOne(lambda *arg: None)
         result = policy.principals_allowed_by_permission(None, 'read')
         self.assertEqual(result, [])
 
@@ -355,22 +373,19 @@ class TestRemoteUserACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
     def test_instance_implements_ISecurityPolicy(self):
         from zope.interface.verify import verifyObject
         from repoze.bfg.interfaces import ISecurityPolicy
-        logger = DummyLogger()
-        verifyObject(ISecurityPolicy, self._makeOne(logger))
+        verifyObject(ISecurityPolicy, self._makeOne())
 
     def test_authenticated_userid(self):
         context = DummyContext()
         request = DummyRequest({'REMOTE_USER':'fred'})
-        logger = DummyLogger()
-        policy = self._makeOne(logger)
+        policy = self._makeOne()
         result = policy.authenticated_userid(request)
         self.assertEqual(result, 'fred')
 
     def test_effective_principals(self):
         context = DummyContext()
         request = DummyRequest({'REMOTE_USER':'fred'})
-        logger = DummyLogger()
-        policy = self._makeOne(logger)
+        policy = self._makeOne()
         result = policy.effective_principals(request)
         from repoze.bfg.security import Everyone
         from repoze.bfg.security import Authenticated
@@ -395,15 +410,13 @@ class TestRepozeWhoIdentityACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
     def test_instance_implements_ISecurityPolicy(self):
         from zope.interface.verify import verifyObject
         from repoze.bfg.interfaces import ISecurityPolicy
-        logger = DummyLogger()
-        verifyObject(ISecurityPolicy, self._makeOne(logger))
+        verifyObject(ISecurityPolicy, self._makeOne())
 
     def test_authenticated_userid(self):
         context = DummyContext()
         identity = {'repoze.who.identity':{'repoze.who.userid':'fred'}}
         request = DummyRequest(identity)
-        logger = DummyLogger()
-        policy = self._makeOne(logger)
+        policy = self._makeOne()
         result = policy.authenticated_userid(request)
         self.assertEqual(result, 'fred')
 
@@ -411,8 +424,7 @@ class TestRepozeWhoIdentityACLSecurityPolicy(unittest.TestCase, PlacelessSetup):
         context = DummyContext()
         identity = {'repoze.who.identity':{'repoze.who.userid':'fred'}}
         request = DummyRequest(identity)
-        logger = DummyLogger()
-        policy = self._makeOne(logger)
+        policy = self._makeOne()
         result = policy.effective_principals(request)
         from repoze.bfg.security import Everyone
         from repoze.bfg.security import Authenticated
@@ -557,6 +569,7 @@ class make_authorizer_factory:
                 authorizer.permission = permission
                 authorizer.principals = principals
                 authorizer.context = context
+                authorizer.logger = logger
                 result = authorizer.expected_context == context
                 if not result and authorizer.intermediates_raise:
                     from repoze.bfg.interfaces import NoAuthorizationInformation