Fixed #24526 -- Combined django.request/security loggers with the root logger.

Thanks Carl Meyer for review.
This commit is contained in:
Tim Graham 2015-03-23 18:17:43 -04:00
parent 37682368a6
commit 8efea1b8d5
8 changed files with 75 additions and 49 deletions

View File

@ -616,3 +616,18 @@ def override_script_prefix(prefix):
Decorator or context manager to temporary override the script prefix. Decorator or context manager to temporary override the script prefix.
""" """
return ScriptPrefix(prefix) return ScriptPrefix(prefix)
class LoggingCaptureMixin(object):
"""
Capture the output from the 'django' logger and store it on the class's
logger_output attribute.
"""
def setUp(self):
self.logger = logging.getLogger('django')
self.old_stream = self.logger.handlers[0].stream
self.logger_output = six.StringIO()
self.logger.handlers[0].stream = self.logger_output
def tearDown(self):
self.logger.handlers[0].stream = self.old_stream

View File

@ -40,17 +40,7 @@ DEFAULT_LOGGING = {
}, },
'loggers': { 'loggers': {
'django': { 'django': {
'handlers': ['console'], 'handlers': ['console', 'mail_admins'],
},
'django.request': {
'handlers': ['mail_admins'],
'level': 'ERROR',
'propagate': False,
},
'django.security': {
'handlers': ['mail_admins'],
'level': 'ERROR',
'propagate': False,
}, },
'py.warnings': { 'py.warnings': {
'handlers': ['console'], 'handlers': ['console'],

View File

@ -358,6 +358,26 @@ template object. These classes have been combined into
:class:`~django.template.base.Origin` and is now always set regardless of the :class:`~django.template.base.Origin` and is now always set regardless of the
engine debug setting. engine debug setting.
.. _default-logging-changes-19:
Changes to the default logging configuration
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
To make it easier to write custom logging configurations, Django's default
logging configuration no longer defines 'django.request' and 'django.security'
loggers. Instead, it defines a single 'django' logger with two handlers:
* 'console': filtered at the ``INFO`` level and only active if ``DEBUG=True``.
* 'mail_admins': filtered at the ``ERROR`` level and only active if
``DEBUG=False``.
If you aren't overriding Django's default logging, you should see minimal
changes in behavior, but you might see some new logging to the ``runserver``
console, for example.
If you are overriding Django's default logging, you should check to see how
your configuration merges with the new defaults.
Miscellaneous Miscellaneous
~~~~~~~~~~~~~ ~~~~~~~~~~~~~

View File

@ -266,12 +266,12 @@ If you use this example, be sure to change the ``'filename'`` path to a
location that's writable by the user that's running the Django application. location that's writable by the user that's running the Django application.
Second, here's an example of how to make the logging system print Django's Second, here's an example of how to make the logging system print Django's
logging to the console. It overrides the fact that ``django.request`` and logging to the console. It may be useful during local development.
``django.security`` don't propagate their log entries by default. It may be
useful during local development.
By default, this config only sends messages of level ``INFO`` or higher to the By default, this config only sends messages of level ``INFO`` or higher to the
console. Django does not log many such messages. Set the environment variable console (same as Django's default logging config, except that the default only
displays log records when ``DEBUG=True``). Django does not log many such
messages. With this config, however, you can also set the environment variable
``DJANGO_LOG_LEVEL=DEBUG`` to see all of Django's debug logging which is very ``DJANGO_LOG_LEVEL=DEBUG`` to see all of Django's debug logging which is very
verbose as it includes all database queries:: verbose as it includes all database queries::
@ -293,6 +293,11 @@ verbose as it includes all database queries::
}, },
} }
.. versionchanged:: 1.9
Django's default logging configuration changed. See :ref:`the release notes
<default-logging-changes-19>` for a description of the changes.
Finally, here's an example of a fairly complex logging setup:: Finally, here's an example of a fairly complex logging setup::
LOGGING = { LOGGING = {
@ -525,14 +530,12 @@ a client that does not match :setting:`ALLOWED_HOSTS`, Django will return a 400
response, and an error message will be logged to the response, and an error message will be logged to the
``django.security.DisallowedHost`` logger. ``django.security.DisallowedHost`` logger.
Only the parent ``django.security`` logger is configured by default, and all These log events will reach the 'django' logger by default, which mails error
child loggers will propagate to the parent logger. The ``django.security`` events to admins when ``DEBUG=False``. Requests resulting in a 400 response due
logger is configured the same as the ``django.request`` logger, and any error to a ``SuspiciousOperation`` will not be logged to the ``django.request``
events will be mailed to admins. Requests resulting in a 400 response due to logger, but only to the ``django.security`` logger.
a ``SuspiciousOperation`` will not be logged to the ``django.request`` logger,
but only to the ``django.security`` logger.
To silence a particular type of SuspiciousOperation, you can override that To silence a particular type of ``SuspiciousOperation``, you can override that
specific logger following this example: specific logger following this example:
.. code-block:: python .. code-block:: python
@ -704,20 +707,20 @@ By default, Django configures the following logging:
When :setting:`DEBUG` is ``True``: When :setting:`DEBUG` is ``True``:
* The ``django`` catch-all logger sends all messages at the ``INFO`` level or * The ``django`` catch-all logger sends all messages at the ``INFO`` level or
higher to the console. Django doesn't make any such logging calls at this higher to the console.
time (all logging is at the ``DEBUG`` level or handled by the
``django.request`` and ``django.security`` loggers).
* The ``py.warnings`` logger, which handles messages from ``warnings.warn()``, * The ``py.warnings`` logger, which handles messages from ``warnings.warn()``,
sends messages to the console. sends messages to the console.
When :setting:`DEBUG` is ``False``: When :setting:`DEBUG` is ``False``:
* The ``django.request`` and ``django.security`` loggers send messages with * The ``django`` logger send messages with ``ERROR`` or ``CRITICAL`` level to
``ERROR`` or ``CRITICAL`` level to :class:`AdminEmailHandler`. These loggers :class:`AdminEmailHandler`.
ignore anything at the ``WARNING`` level or below and log entries aren't
propagated to other loggers (they won't reach the ``django`` catch-all .. versionchanged:: 1.9
logger, even when ``DEBUG`` is ``True``).
Django's default logging configuration changed. See :ref:`the release notes
<default-logging-changes-19>` for a description of the changes.
See also :ref:`Configuring logging <configuring-logging>` to learn how you can See also :ref:`Configuring logging <configuring-logging>` to learn how you can
complement or replace this default logging configuration. complement or replace this default logging configuration.

View File

@ -9,7 +9,7 @@ from admin_scripts.tests import AdminScriptTestCase
from django.core import mail from django.core import mail
from django.core.files.temp import NamedTemporaryFile from django.core.files.temp import NamedTemporaryFile
from django.test import RequestFactory, TestCase, override_settings from django.test import RequestFactory, TestCase, override_settings
from django.test.utils import patch_logger from django.test.utils import LoggingCaptureMixin, patch_logger
from django.utils.deprecation import RemovedInNextVersionWarning from django.utils.deprecation import RemovedInNextVersionWarning
from django.utils.encoding import force_text from django.utils.encoding import force_text
from django.utils.log import ( from django.utils.log import (
@ -65,26 +65,18 @@ class LoggingFiltersTest(TestCase):
self.assertEqual(filter_.filter("record is not used"), False) self.assertEqual(filter_.filter("record is not used"), False)
class DefaultLoggingTest(TestCase): class DefaultLoggingTest(LoggingCaptureMixin, TestCase):
def setUp(self):
self.logger = logging.getLogger('django')
self.old_stream = self.logger.handlers[0].stream
def tearDown(self):
self.logger.handlers[0].stream = self.old_stream
def test_django_logger(self): def test_django_logger(self):
""" """
The 'django' base logger only output anything when DEBUG=True. The 'django' base logger only output anything when DEBUG=True.
""" """
output = StringIO()
self.logger.handlers[0].stream = output
self.logger.error("Hey, this is an error.") self.logger.error("Hey, this is an error.")
self.assertEqual(output.getvalue(), '') self.assertEqual(self.logger_output.getvalue(), '')
with self.settings(DEBUG=True): with self.settings(DEBUG=True):
self.logger.error("Hey, this is an error.") self.logger.error("Hey, this is an error.")
self.assertEqual(output.getvalue(), 'Hey, this is an error.\n') self.assertEqual(self.logger_output.getvalue(), 'Hey, this is an error.\n')
class WarningLoggerTests(TestCase): class WarningLoggerTests(TestCase):
@ -167,11 +159,10 @@ class CallbackFilterTest(TestCase):
class AdminEmailHandlerTest(TestCase): class AdminEmailHandlerTest(TestCase):
logger = logging.getLogger('django.request') logger = logging.getLogger('django')
def get_admin_email_handler(self, logger): def get_admin_email_handler(self, logger):
# Inspired from views/views.py: send_log() # Ensure that AdminEmailHandler does not get filtered out
# ensuring the AdminEmailHandler does not get filtered out
# even with DEBUG=True. # even with DEBUG=True.
admin_email_handler = [ admin_email_handler = [
h for h in logger.handlers h for h in logger.handlers

View File

@ -19,6 +19,7 @@ from django.utils._os import upath
from django.utils.deprecation import ( from django.utils.deprecation import (
RemovedInDjango20Warning, RemovedInDjango21Warning, RemovedInDjango20Warning, RemovedInDjango21Warning,
) )
from django.utils.log import DEFAULT_LOGGING
warnings.simplefilter("error", RemovedInDjango20Warning) warnings.simplefilter("error", RemovedInDjango20Warning)
warnings.simplefilter("error", RemovedInDjango21Warning) warnings.simplefilter("error", RemovedInDjango21Warning)
@ -144,6 +145,11 @@ def setup(verbosity, test_labels):
'auth': 'django.contrib.auth.tests.migrations', 'auth': 'django.contrib.auth.tests.migrations',
'contenttypes': 'contenttypes_tests.migrations', 'contenttypes': 'contenttypes_tests.migrations',
} }
log_config = DEFAULT_LOGGING
# Filter out non-error logging so we don't have to capture it in lots of
# tests.
log_config['loggers']['django']['level'] = 'ERROR'
settings.LOGGING = log_config
if verbosity > 0: if verbosity > 0:
# Ensure any warnings captured to logging are piped through a verbose # Ensure any warnings captured to logging are piped through a verbose

View File

@ -16,6 +16,7 @@ from django.core.files.uploadedfile import SimpleUploadedFile
from django.core.urlresolvers import reverse from django.core.urlresolvers import reverse
from django.template.base import TemplateDoesNotExist from django.template.base import TemplateDoesNotExist
from django.test import RequestFactory, TestCase, override_settings from django.test import RequestFactory, TestCase, override_settings
from django.test.utils import LoggingCaptureMixin
from django.utils import six from django.utils import six
from django.utils.encoding import force_bytes, force_text from django.utils.encoding import force_bytes, force_text
from django.utils.functional import SimpleLazyObject from django.utils.functional import SimpleLazyObject
@ -48,7 +49,7 @@ class CallableSettingWrapperTests(TestCase):
@override_settings(DEBUG=True, ROOT_URLCONF="view_tests.urls") @override_settings(DEBUG=True, ROOT_URLCONF="view_tests.urls")
class DebugViewTests(TestCase): class DebugViewTests(LoggingCaptureMixin, TestCase):
def test_files(self): def test_files(self):
response = self.client.get('/raises/') response = self.client.get('/raises/')
@ -642,7 +643,7 @@ class ExceptionReportTestMixin(object):
@override_settings(ROOT_URLCONF='view_tests.urls') @override_settings(ROOT_URLCONF='view_tests.urls')
class ExceptionReporterFilterTests(TestCase, ExceptionReportTestMixin): class ExceptionReporterFilterTests(ExceptionReportTestMixin, LoggingCaptureMixin, TestCase):
""" """
Ensure that sensitive information can be filtered out of error reports. Ensure that sensitive information can be filtered out of error reports.
Refs #14614. Refs #14614.
@ -833,7 +834,7 @@ class ExceptionReporterFilterTests(TestCase, ExceptionReportTestMixin):
self.assertNotContains(response, 'should not be displayed', status_code=500) self.assertNotContains(response, 'should not be displayed', status_code=500)
class AjaxResponseExceptionReporterFilter(TestCase, ExceptionReportTestMixin): class AjaxResponseExceptionReporterFilter(ExceptionReportTestMixin, LoggingCaptureMixin, TestCase):
""" """
Ensure that sensitive information can be filtered out of error reports. Ensure that sensitive information can be filtered out of error reports.

View File

@ -102,7 +102,7 @@ def render_no_template(request):
def send_log(request, exc_info): def send_log(request, exc_info):
logger = logging.getLogger('django.request') logger = logging.getLogger('django')
# The default logging config has a logging filter to ensure admin emails are # The default logging config has a logging filter to ensure admin emails are
# only sent with DEBUG=False, but since someone might choose to remove that # only sent with DEBUG=False, but since someone might choose to remove that
# filter, we still want to be able to test the behavior of error emails # filter, we still want to be able to test the behavior of error emails