Fix log level out of sync with debug mode

Debug mode can be set with `app.debug = True` which does not update
the logger level from ERROR to DEBUG. This is has been replaced with a
setter that reconfigures the log level after debug is reset. The
initialization method on the Chalice class had some logic that checked
what the debug value was and configured the logger to match; however,
debug was hardcoded to be False so this never did anything useful. A
debug parameter has been added to the the __init__ method to make this
more useful, it defaults to False.

fixes aws#386

chalice/app.py

@@ -418,12 +418,12 @@ class Chalice(object):
 
     FORMAT_STRING = '%(name)s - %(levelname)s - %(message)s'
 
-    def __init__(self, app_name, configure_logs=True, env=None):
+    def __init__(self, app_name, debug=False, configure_logs=True, env=None):
         self.app_name = app_name
         self.api = APIGateway()
         self.routes = defaultdict(dict)
         self.current_request = None
-        self.debug = False
+        self._debug = debug
         self.configure_logs = configure_logs
         self.log = logging.getLogger(self.app_name)
         self.builtin_auth_handlers = []
@@ -441,22 +441,26 @@ def _initialize(self, env):
             __version__,
         )
 
+    @property
+    def debug(self):
+        return self._debug
+
+    @debug.setter
+    def debug(self, value):
+        self._debug = value
+        self._configure_log_level()
+
     def _configure_logging(self):
-        log = logging.getLogger(self.app_name)
-        if self._already_configured(log):
+        if self._already_configured(self.log):
             return
         handler = logging.StreamHandler(sys.stdout)
         # Timestamp is handled by lambda itself so the
         # default FORMAT_STRING doesn't need to include it.
         formatter = logging.Formatter(self.FORMAT_STRING)
         handler.setFormatter(formatter)
-        log.propagate = False
-        if self.debug:
-            level = logging.DEBUG
-        else:
-            level = logging.ERROR
-        log.setLevel(level)
-        log.addHandler(handler)
+        self.log.propagate = False
+        self._configure_log_level()
+        self.log.addHandler(handler)
 
     def _already_configured(self, log):
         if not log.handlers:
@@ -467,6 +471,13 @@ def _already_configured(self, log):
                     return True
         return False
 
+    def _configure_log_level(self):
+        if self._debug:
+            level = logging.DEBUG
+        else:
+            level = logging.ERROR
+        self.log.setLevel(level)
+
     def authorizer(self, name=None, **kwargs):
         def _register_authorizer(auth_func):
             auth_name = name

tests/unit/test_app.py

@@ -1185,3 +1185,32 @@ def index(b, a):
     response = demo(event, context=None)
     response = json_response_body(response)
     assert response == {'a': 'first', 'b': 'second'}
+
+
+def test_ensure_debug_mode_is_false_by_default():
+    # These logger tests need to each have a unique name because the Chalice
+    # app creates a logger with it's name. If these tests are run in a batch
+    # the logger names will overlap in the logging module and cause test
+    # failures.
+    test_app = app.Chalice('logger-test-1')
+    assert test_app.debug is False
+    assert test_app.log.getEffectiveLevel() == logging.ERROR
+
+
+def test_can_explicitly_set_debug_false_in_initializer():
+    test_app = app.Chalice('logger-test-2', debug=False)
+    assert test_app.debug is False
+    assert test_app.log.getEffectiveLevel() == logging.ERROR
+
+
+def test_can_set_debug_mode_in_initialzier():
+    test_app = app.Chalice('logger-test-3', debug=True)
+    assert test_app.debug is True
+    assert test_app.log.getEffectiveLevel() == logging.DEBUG
+
+
+def test_debug_mode_changes_log_level():
+    test_app = app.Chalice('logger-test-4', debug=False)
+    test_app.debug = True
+    assert test_app.debug is True
+    assert test_app.log.getEffectiveLevel() == logging.DEBUG