Django logging set up

转载自：https://www.webforefront.com/django/setupdjangologging.html

红底部分是我的note，目前估计是因为dango版本的原因导致有些信息有误，等搜集到更多的信息后，再整理这个blog

Django logging set up

Problem

You want to set up Django logging to debug a project's workflow or detect potential errors.

Solution

Set up loggers in your Django project files using the getLogger method of the Python logging package. Next, define logging messages with one of several logger methods: <logger_name>.critical(), <logger_name>.error(), <logger_name>.warning(), <logger_name>.info() or <logger_name>.debug().

Configure the LOGGING variable in settings.py to process logging messages from your loggers. Set up different handlers in the LOGGING variable to send logging messages to different destinations (e.g. console, file, email). Set up a logging level in either the loggers or handlers section of the LOGGING variable to establish a logging threshold. Optionally set up filters in the LOGGING variable to further refine the type of logging messages that get reported. Optionally set up formatters in the LOGGING variable to customize the final logging output.

How it works

Python core logging concepts

Django is built on top of Python's logging package. The Python logging package provides a robust and flexible way to setup application logging. In case you've never used Python's logging package, I'll provide a brief overview of its core concepts. There are four core concepts in Python logging:

• Loggers.- Provide the initial entry point to group logging messages. Generally, each Python module (i.e. .py file) has a single logger to assign its logging messages. However, it's also possible to define multiple loggers in the same module (e.g. one logger for business logic, another logger for database logic,etc). In addition, it's also possible to use the same logger across multiple Python modules or .py files.
• Handlers.- Are used to redirect log messages (created by loggers) to a destination. Destinations can include flat files, a server's console, an email or SMS messages, among other destinations. It's possible to use more than one handler for the same logger.
• Filters.- Offer a way to apply fine grained rules on certain logging messages. For example, you can filter logging messages generated by the same logger but on different methods and send them to different handlers.
• Formatters.- Are used to specify the final format for log messages.

With this brief overview of Python logging concepts, let's jump straight into exploring Django's default logging functionality.

Exploring how Django's default logging works

The logging configuration for Django projects is defined in the LOGGING variable in settings.py. For the moment, don't even bother opening your project's settings.py file because you won't see LOGGING in it. This variable isn't hard-coded when you create a project, but it does have some logging values in effect if it isn't declared. Listing 1 shows the default LOGGING values if it isn't declared in settings.py.

Listing 1 - Default LOGGING in Django projects

LOGGING = {    'version': 1,    'disable_existing_loggers': False,    'filters': {        'require_debug_false': {            '()': 'django.utils.log.RequireDebugFalse',        },        'require_debug_true': {            '()': 'django.utils.log.RequireDebugTrue',        },    },    'handlers': {        'console': {            'level': 'INFO',            'filters': ['require_debug_true'],            'class': 'logging.StreamHandler',        },        'null': {            'class': 'logging.NullHandler',        },        'mail_admins': {            'level': 'ERROR',            'filters': ['require_debug_false'],            'class': 'django.utils.log.AdminEmailHandler'        }    },    'loggers': {        'django': {            'handlers': ['console'],        },        'django.request': {            'handlers': ['mail_admins'],            'level': 'ERROR',            'propagate': False,        },        'django.security': {            'handlers': ['mail_admins'],            'level': 'ERROR',            'propagate': False,        },        'py.warnings': {            'handlers': ['console'],        },    }}

n summary, the default Django logging settings illustrated in listing 1 have the following logging behaviors:

• Console logging or the console handler will only be done when DEBUG=True, for logging messages worse than INFO (inclusive) and only for the Python package django -- and its children django.request,django.contrib,etc -- as well as the Python package py.warnings.
• Admin logging or the mail_admins handler -- which sends emails to ADMINS -- will only be done when DEBUG=False, for logging messages worse than ERROR (inclusive) and only for the Python packages django.request and django.security.

Now lets break down the handlers section in listing 1. Handlers define locations to send logging messages and there are three in listing 1: console, null and mail_admins. The handler names by themselves do nothing -- they are simply reference names -- the relevant actions are defined in the associated properties dictionary. All the handlers have a class property which defines the backing Python class that does the actual work.
The console handler is assigned the logging.StreamHandler class which is part of the core Python logging package. This class sends logging output to streams such as standard input and standard error, which as the handler name suggests is technically the system console or screen where Django runs. The null handler is assigned the logging.NullHandler class which is also part of the core Python logging package and which generates no output. And the mail_admins handler is assigned the django.utils.log.AdminEmailHandler class that is a Django custom handler utility, which sends logging output as an email to people defined as ADMINS in settings.py -- see the previous recipe Django settings.py for the real world: Security, absolute paths and multiple environments/files for more information on the ADMINS variable.

Another property in Django handlers is level which defines the threshold level at which the handler will accept logging messages. There are five threshold levels for Python logging, from worst to least worst they are: CRITICAL, ERROR, WARNING, INFO and DEBUG. The INFO level for the console handler indicates that all logging messages worse or equal to INFO -- which is every level, except DEBUG -- will make it to the handler, a reasonable setting as the console can handle many messages. The ERROR level for the mail_admins handler indicates that only messages worse or equal to ERROR -- which is just CRITICAL -- will make it to the handler, a reasonable setting as only the two worst types of error messages will trigger emails to administrators.

The other property in Django handlers is filters which defines an additional layer to restrict logging messages for a handler. Handlers can accept multiple filters, which is why the filters property accepts a Python list. The console handler has a single filter require_debug_true and the mail_admins handler has a single filter require_debug_false. Filters are defined in their own block as you can observe in listing 1. The require_debug_false filter is backed by the django.utils.log.RequireDebugFalse class which checks if a project has DEBUG=False, where as the require_debug_true filter is backed by the django.utils.log.RequireDebugTrue class which checks if a project has DEBUG=True. This means the console handler will only accept logging messages if a Django project has DEBUG=True and the mail_admins handler will only accept logging messages if a Django project has DEBUG=False.

Now that you understand handlers and filters, lets take a look at loggers. Logger definitions generally map directly to Python packages and have parent-child relationships. For example, Python modules (i.e. .py files) that belong to a package named coffeehouse will generally have a logger named coffeehouse and Python modules that belong to the package coffeehouse.about will generally have a logger named coffeehouse.about. The dot notation in logger names also represents a parent-child relationship, so the coffeehouse.about logger is considered the child of the coffeehouselogger.

In listing 1 there are four loggers: django, django.request, django.security and py.warnings. The django logger indicates that all logging messages associated with it and its children be processed by the console handler.

The django.request logger indicates that all logging messages associated with it and its children be processed by the mail_admins handler. The django.request logger also has the 'level':'ERROR' property to provide the threshold level at which the logger will accept logging messages -- a property that overrides the handler level property. And in addition, the django.request logger also has the 'propagate':'False' to indicate the logger should not propagate messages to parent loggers (e.g. django is the parent of django.request).

Next, we have the django.security logger which is identical in functionality to the django.request logger. And the py.warnings which indicates that all logging messages associated with it and its children be processed by the console handler.

Finally there are the first two lines in listing 1 which are associated with Python logging in general. The version key identifies the configuration version as 1, which at present is the only Python logging version. And the disable_existing_loggers key is used to disable all existing Python loggers. If disable_existing_loggers is False it keeps the pre-existing logger values and if it's set to True it disables all pre-existing loggers values. Note that if you use 'disable_existing_loggers': False in your own LOGGING variable you can redefine/override some or all of the pre-existing logger values.

Now that you have a firm understanding of what Django logging does in its default state, I'll describe how to create logging messages in a Django project and finish the recipe with a custom LOGGING configuration.

Create logging messages in a Django project

At the top of any Python module or .py file you can create loggers by using the getLogger method of the logging package. The getLogger method receives the name of the logger as its input parameter. Listing 2 illustrates the creation of two logger instances using __name__ and the hard-coded dba name.

Listing 2 - Define loggers in a Python module

# Python logging packageimport logging# Standard instance of a logger with __name__stdlogger = logging.getLogger(__name__)# Custom instance logging with explicit namedbalogger = logging.getLogger('dba')

The Python __name__ syntax used for getLogger in listing 1 automatically assigns the package name as the logger name. This means if the logger is defined in a module under the application directory coffeehouse/about/views.py, the logger receives the name coffeehouse.about.views. So by relying on the __name__ syntax, loggers are automatically created based on the origin of the logging message.
Don't worry about potentially having dozens or hundreds of loggers in a Django project for each module or .py file. As described in the past section, Python logging works with inheritance, so you can define a single handler for a parent logger (e.g. coffeehouse) that handles all children loggers (e.g. coffeehouse.about, coffeehouse.about.views,coffeehouse.drinks, coffeehouse.drinks.models, etc).
Sometimes it's convenient to define a logger with an explicit name to classify certain types of messages. In listing 2 you can see a logger named dba that will be used for messages related to databases issues. This way database administrators can consult their own logging stream without the need to see logging messages from other parts of the application.
Once you have loggers in a module or .py file, you can define logging messages with one of several methods depending on the severity of a message that needs to be reported. These methods are illustrated in the following list:
<logger_name>.critical().- Most severe logging level. Use it to report potentially catastrophic application events (e.g. something that can halt or crash an application).
<logger_name>.error().- Second most severe logging level. Use it to report important events (e.g. unexpected behaviors or conditions that cause end users to see an error)
<logger_name>.warning().- Mid-level logging level. Use it to report relatively important events (e.g. unexpected behaviors or conditions that shouldn't happen, yet don't cause end users to notice the issue).
<logger_name>.info().- Informative logging level. Use it to report informative events in an application (e.g. application milestones or user activity)
<logger_name>.debug().- Debug logging level. Use it to report step by step logic that can be difficult to write (e.g. complex business logic or database queries)
<logger_name>.log().- Use it to manually emit logging messages with a specific log level.
<logger_name>.exception().- Use it to create an error level logging message, wrapped with the current exception stack.

What methods you use to log messages across your project depends entirely up to you. As far as the logging levels are concerned, just try to be consistent with the selection criteria. You can always adjust the run-time logging level to deactivate logging messages of a certain level, as described in the previous section. In addition, I would also recommend you use the most descriptive logging messages possible to maximize the benefits of logging.

Listing 3 illustrates a series of examples using several logging methods and messages:

Listing 3 - Define logging messages in a Python module

# Python logging packageimport logging# Standard instance of a logger with __name__stdlogger = logging.getLogger(__name__)# Custom instance logging with explicit namedbalogger = logging.getLogger('dba')def index(request):     stdlogger.debug("Entering index method")def contactform(request):     stdlogger.info("Call to contactform method")            try:          stdlogger.debug("Entering store_id conditional block") # Logic to handle store_id    except Exception, e:         stdlogger.exception(e)    stdlogger.info("Starting search on DB")        try:          stdlogger.info("About to search db") # Loging to search db     except Exception, e:         stdlogger.error("Error in searchdb method") dbalogger.error("Error in searchdb method, stack %s" % (e)) 

If you place the loggers and logging statements like the ones in listing 3 in a Django project, you'll see that nothing happens logging wise. In fact, what you'll see in your logs are messages in the form 'No handlers could be found for logger ...<logger_name>'. This is because by default Django doesn't know anything about your loggers, it only knows about the default loggers described in the past section. Next, lets take a look at a custom LOGGING configuration so you can see your project's logging messages.

(Note: I use django 1.11.2'No handlers could be found for logger ...<logger_name>' issue will not occur)

Custom Django logging to send output to multiple files and modify default logging behavior

Let's start with a set of logging requirements to define our custom Django logging. The following list illustrates some modified requirements from the default logging behavior and new logging requirements.

• Modify the console handler to output logging message from the DEBUG level, instead of the default INFO level.
• Disable all email sent to ADMINS via the mail_admins handler for the django.request and django.security loggers.
• Add two custom logging formatters to enhance the logging output.
• Add a new handler as a file for logging messages from all loggers, for the DEBUG level and that only functions when DEBUG=True.
• Add a new handler as a file for logging messages from all loggers except py.warnings, for the ERROR level and that only functions when DEBUG=False.
• Add a new handler as a file for logging messages from the dba logger, for the DEBUG level and that functions when either DEBUG=False or DEBUG=True.

Listing 4 illustrates a custom LOGGING configuration that covers the requirements from the past list.

Listing 4 - Custom LOGGING Django configuration

LOGGING = {    'version': 1,    'disable_existing_loggers': True,    'filters': {        'require_debug_false': {            '()': 'django.utils.log.RequireDebugFalse',        },        'require_debug_true': {            '()': 'django.utils.log.RequireDebugTrue',        },    },    'formatters': {        'simple': {            'format': '[%(asctime)s] %(levelname)s %(message)s',    'datefmt': '%Y-%m-%d %H:%M:%S'        },        'verbose': {            'format': '[%(asctime)s] %(levelname)s [%(name)s.%(funcName)s:%(lineno)d] %(message)s',    'datefmt': '%Y-%m-%d %H:%M:%S'        },    },    'handlers': {        'console': {            'level': 'DEBUG',            'filters': ['require_debug_true'],            'class': 'logging.StreamHandler',            'formatter': 'simple'        },        'development_logfile': {            'level': 'DEBUG',            'filters': ['require_debug_true'],            'class': 'logging.FileHandler',            'filename': '/tmp/django_dev.log',            'formatter': 'verbose'        },        'production_logfile': {            'level': 'ERROR',            'filters': ['require_debug_false'],            'class': 'logging.FileHandler',            'filename': '/var/log/django_production.log',            'formatter': 'simple'        },        'dba_logfile': {            'level': 'DEBUG',            'filters': ['require_debug_false','require_debug_true'],            'class': 'logging.FileHandler',            'filename': '/var/log/django_dba.log',            'formatter': 'simple'        },    },    'loggers': {        'coffeehouse': {            'handlers': ['console','development_logfile','production_logfile'],         },        'dba': {            'handlers': ['console','dba_logfile'],        },        'django': {            'handlers': ['console','development_logfile','production_logfile'],        },        'py.warnings': {            'handlers': ['console','development_logfile'],        },    }}

The first important definition in listing 4 is 'disable_existing_loggers':True which disables Django's default loggers from listing 1. If you want to keep Django's default loggers from listing 1, set this value to False and be sure not to override any of these loggers as we do in listing 4, as any explicit LOGGING configuration in settings.py takes precedence over Django defaults even when 'disable_existing_loggers':False.

Next, we have the same default filters section as listing 1. Note that we need to redefine this section because we will use the same filters in our loggers section. Then we have the formatterssection that will allow us to generate logging messages with a simpler and more verbose output.

By default, all Python logging messages follow the format %(levelname)s:%(name)s:%(message)s, which means "Output the log message level, followed by the name of the logger and the log message itself". However, there is a lot more information available through Python logging that can make logging messages more comprehensive. As you can see in listing 4, we define the simpleand verbose formatters using a special syntax and a series of fields that are different from the default. Table 1 illustrates the different Python formatter fields including their syntax and meaning.

Table 1 - Python logging formatter fields

Field syntaxDescription%(name)sName of the logger (logging channel)%(levelno)sNumeric logging level for the message (DEBUG, INFO,WARNING, ERROR, CRITICAL)%(levelname)sText logging level for the message ("DEBUG", "INFO","WARNING", "ERROR", "CRITICAL")%(pathname)sFull pathname of the source file where the logging call was issued (if available)%(filename)sFilename portion of pathname%(module)sModule (name portion of filename)%(lineno)dSource line number where the logging call was issued (if available)%(funcName)sFunction name%(created)fTime when the log record was created (time.time() return value)%(asctime)sTextual time when the log record was created%(msecs)dMillisecond portion of the creation time%(relativeCreated)dTime in milliseconds when the log record was created,relative to the time the logging module was loaded (typically at application startup time)%(thread)dThread ID (if available)%(threadName)sThread name (if available)%(process)dProcess ID (if available)%(message)sThe result of record.getMessage(), computed just as the record is emitted
You can add or remove fields to the format field of each formatter as you see necessary based on the fields in table 1. In addition to the format field for each formatter, there's also the datefmtfield that allows us to define the date/time format for each logging message, which will correspond to the output of the %(asctime)s format field. Note that the syntax for the datefmt field follows Python's strftime() format.

Next comes the four logging handlers or locations to send logging messages. First is the console handler which is identical to the default in listing 1, except it's set to the DEBUG level and uses our custom simple formatter. The remaining three handlers are all configured for file output via the 'class': 'logging.FileHandler' statement.

The development_logfile handler is configured to work for logging messages worse than DEBUG (inclusive) -- which is technically all logging messages -- and only when DEBUG=True due to the require_debug_true filter. In addition, the development_logfile handler is set to send output to the file /tmp/django_dev.log and use our custom verbose formatter.

The production_logfile handler is configured to work for logging messages worse than ERROR (inclusive) -- which is just ERROR and CRITICAL logging messages -- and only when DEBUG=False due to the require_debug_false filter. In addition, the handler uses the custom simpler formatter and is set to send output to the file /var/log/django_production.log.

The dba_logfile is configured to work for logging messages worse than DEBUG (inclusive) -- which is technically all logging messages -- and when DEBUG=True or DEBUG=False due to the require_debug_true and require_debug_false filters. In addition, the handler uses the custom simpler formatter and is set to send output to the file /var/log/django_dba.log.

Then we come to the loggers section. The first logger coffeehouse indicates to link all the logging messages for itself and its children (e.g. coffeehouse.about, coffeehouse.about.views and coffeehouse.drinks) to the handlers console, development_logfile and production_logfile. Recall that by using Python's __name__ syntax to define loggers -- see listing 2 -- the name of the loggers ends up being based on the Python package structure.

Next, you can see the custom dba logger which links all its logging messages to the handlers console and dba_logfile. In this case, the handlers are limited because this is a special logger intended for database administrators, so output will only go to the console and a dedicated file with these type of messages.

Finally, we define the django and py.warnings loggers to re-establish some of Django's default behavior because we set 'disable_existing_loggers': True. The django logger links all its logging messages to the handlers console, development_logfile and production_logfile, since we want logging messages associated with the django logger and its children (e.g. django.request, django.security) to go to the console and two of the log files. Notice we don't declare explicit loggers for django.request and django.security unlike the default's in listing 1, since we will use the same handlers for the django logger and its children. At the end, the py.warnings logger links all its logging messages to the handlers console and development_logfile, as we don't want any trace of py.warnings logging messages in production log files.

 使用上述配置后还是无法输出debug 或者info 级别的信息。我查看了python 官方文档，发现logger 和 handler各自有独立的level，我试着在logger 配置里面添加了level就可以输出debug level的信息了。

'loggers': {    'coffeehouse': {        'handlers': ['console','development_logfile','production_logfile'],        'level': 'DEBUG'     },    'dba': {        'handlers': ['console','dba_logfile'],    },    'django': {        'handlers': ['console','development_logfile','production_logfile'],    },    'py.warnings': {        'handlers': ['console','development_logfile'],    },}