Tech blog: github.com/yongxinz/te…

Meanwhile, welcome to follow my wechat official account AlwaysBeta, more exciting content waiting for you.

Journaling is a good thing, but not everyone wants to keep it until something goes wrong and they wish they had.

But journaling is a skill. You can’t do nothing, but you can’t do everything. If you memorize a lot of useless information, it will add a lot of difficulties to the troubleshooting process.

Therefore, the log should be recorded at key points of the program, and the content should be concise and the information should be transmitted accurately. Clearly reflect the status of the program, time, error messages, etc.

Only in this way can we find problems and solve them in the first place.

Logging structure

Django uses Python’s standard library logging module for logging. I won’t cover the logging configuration here, but the four most important parts: Loggers, Handlers, Filters, and Formatters.

Loggers

Logger is the entry point of the log system. It has three important jobs:

  • Expose several methods to your application (that is, your project) to log messages at run time
  • According to passing toLoggerDetermines whether the message needs to be processed
  • The message that needs processing is passed to all interested processorsHandler

Each message written to Logger is a log record, and each log record contains a level that represents the severity of the corresponding message. The common levels are as follows:

  • DEBUG: Low-level system information used for troubleshooting, usually used during development
  • INFO: General system information, not a problem
  • WARNING: Describes information about minor problems that occur in the system, but usually do not affect function
  • ERROR: Indicates that a major problem occurs in the system, which may cause abnormal functions
  • CRITICAL: Indicates that a serious problem has occurred in the system and that the application is at risk of crashing

When a Logger processes a message, it compares its log level to the configured level of the message. If the message level matches or exceeds Logger’s log level, it is further processed, otherwise the message is ignored.

When Logger determines that a message needs to be processed, it passes it to Handler.

Handlers

A Handler is a processor whose main function is to determine how to process each message in a Logger, such as output to a screen, file, or Email.

Like loggers, handlers have a concept of levels. If the level of a log does not match or is lower than that of the Handler, the log is ignored by the Handler.

A Logger can have multiple handlers, and each Handler can have a different log level. This allows you to provide different types of output depending on the importance of the message. For example, you can add a Handler to send ERROR and CRITICAL messages to your Email, and another Handler to save all messages (including ERROR and CRITICAL messages) to a file.

Filters

A Filter is a Filter. Filter is used for additional control during logging from Logger to Handler. For example, only ERROR messages from a particular source are allowed to be output.

Filter is also used to modify log records before they are output. For example, if certain conditions are met, the log level is reduced from ERROR to WARNING.

Filters can be added to both Logger and Handler, and multiple filters can be linked together to perform multiple filtering operations.

Formaters

A Formatter determines the form and content of the final output.

implementation

With all the theory behind it, it’s time to see how it works.

The easiest way to do this is to simply import from the top of the file and call it from the program like this:

# import the logging library
import logging

# Get an instance of a logger
logging.basicConfig(
    format='%(asctime)s - %(pathname)s[%(lineno)d] - %(levelname)s: %(message)s',
    level=logging.INFO)
logger = logging.getLogger(__name__)

def my_view(request, arg1, arg):.if bad_mojo:
        # Log an error message
        logger.error('Something went wrong! ')
Copy the code

But this approach is not good, if at the beginning of each file to write this again, first is troublesome, second is if one day to change the format of the output log, that every file to change again, is not tiring.

Obviously, if you can encapsulate it into a class, call it when you use it, and only change it when you modify it, wouldn’t that solve the problem?

Custom class

Let’s see how this class is encapsulated:

class CommonLog(object):
    """ logging """
    def __init__(self, logger, logname='web-log'):
        self.logname = os.path.join(settings.LOGS_DIR, '%s' % logname)
        self.logger = logger
        self.logger.setLevel(logging.DEBUG)
        self.logger.propagate = False
        self.formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s: %(message)s'.'%Y-%m-%d %H:%M:%S')

    def __console(self, level, message):
        Create a FileHandler that will be written locally
        fh = logging.handlers.TimedRotatingFileHandler(self.logname, when='MIDNIGHT', interval=1, encoding='utf-8')
        # fh = logging.FileHandler(self.logname, 'a', encoding='utf-8')
        fh.suffix = '%Y-%m-%d.log'
        fh.setLevel(logging.DEBUG)
        fh.setFormatter(self.formatter)
        self.logger.addHandler(fh)

        Create a StreamHandler for output to the console
        ch = logging.StreamHandler()
        ch.setLevel(logging.DEBUG)
        ch.setFormatter(self.formatter)
        self.logger.addHandler(ch)

        if level == 'info':
            self.logger.info(message)
        elif level == 'debug':
            self.logger.debug(message)
        elif level == 'warning':
            self.logger.warning(message)
        elif level == 'error':
            self.logger.error(message)

        These two lines of code are designed to avoid duplicate log output problems
        self.logger.removeHandler(ch)
        self.logger.removeHandler(fh)
        # Close open files
        fh.close()

    def debug(self, message):
        self.__console('debug', message)

    def info(self, message):
        self.__console('info', message)

    def warning(self, message):
        self.__console('warning', message)

    def error(self, message):
        self.__console('error', message)
Copy the code

This is a piece of code THAT I still use in my project, which generates files that are shard by day.

When I was writing this code, I had a problem for a long time, which was the problem of showing the number of lines in the code. When formatter is configured with %(lineno)d, instead of displaying the actual error line each time, it displays the line of code in the logging class, but this rendering is meaningless, so there is no configuration, and %(name)s is used to display the actual calling file.

In fact, if it is just for troubleshooting convenience and logging, this class will probably do the job. But if you want to log all requests to access the system, you can’t, because you can’t manually log every interface code, and you don’t need to.

At this point, Django middleware comes naturally to mind.

Django middleware

The middleware logging code is divided into three parts: Filters code, Middleware code, Settings configuration, as follows:

local = threading.local()


class RequestLogFilter(logging.Filter):
    """ Log filter ""

    def filter(self, record):
        record.sip = getattr(local, 'sip'.'none')
        record.dip = getattr(local, 'dip'.'none')
        record.body = getattr(local, 'body'.'none')
        record.path = getattr(local, 'path'.'none')
        record.method = getattr(local, 'method'.'none')
        record.username = getattr(local, 'username'.'none')
        record.status_code = getattr(local, 'status_code'.'none')
        record.reason_phrase = getattr(local, 'reason_phrase'.'none')

        return True
      

class RequestLogMiddleware(MiddlewareMixin):
    """ Logs the request information to the current requesting thread. "" "

    def __init__(self, get_response=None):
        self.get_response = get_response
        self.apiLogger = logging.getLogger('web.log')

    def __call__(self, request):

        try:
            body = json.loads(request.body)
        except Exception:
            body = dict()

        if request.method == 'GET':
            body.update(dict(request.GET))
        else: body.update(dict(request.POST)) local.body = body local.path = request.path local.method = request.method local.username  = request.user local.sip = request.META.get('REMOTE_ADDR'.' ')
        local.dip = socket.gethostbyname(socket.gethostname())

        response = self.get_response(request)
        local.status_code = response.status_code
        local.reason_phrase = response.reason_phrase
        self.apiLogger.info('system-auto')

        return response
Copy the code

Settings. py file configuration:

MIDDLEWARE = [
    'django.middleware.security.SecurityMiddleware'.'django.contrib.sessions.middleware.SessionMiddleware'.'django.middleware.common.CommonMiddleware'.'django.middleware.csrf.CsrfViewMiddleware'.'django.contrib.auth.middleware.AuthenticationMiddleware'.'django.contrib.messages.middleware.MessageMiddleware'.'django.middleware.clickjacking.XFrameOptionsMiddleware'.# Custom middleware added at the end
    'lib.log_middleware.RequestLogMiddleware'
]

LOGGING = {
    # version
    'version': 1.Whether to disable loggers configured by default
    'disable_existing_loggers': False.'formatters': {
        'standard': {
            'format': '{"time": "%(asctime)s", "level": "%(levelname)s", "method": "%(method)s", "username": "%(username)s", "sip": "%(sip)s", "dip": "%(dip)s", "path": "%(path)s", "status_code": "%(status_code)s", "reason_phrase": "%(reason_phrase)s", "func": "%(module)s.%(funcName)s:%(lineno)d", "message": "%(message)s"}'.'datefmt': '%Y-%m-%d %H:%M:%S'}},# filter
    'filters': {
        'request_info': {'()': 'lib.log_middleware.RequestLogFilter'}},'handlers': {
        # Standard output
        'console': {
            'level': 'ERROR'.'class': 'logging.StreamHandler'.'formatter': 'standard'
        },
        Custom Handlers, output to a file
        'restful_api': {
            'level': 'DEBUG'.# Time scrolling shards
            'class': 'logging.handlers.TimedRotatingFileHandler'.'filename': os.path.join(LOGS_DIR, 'web-log.log'),
            'formatter': 'standard'.# call filter
            'filters': ['request_info'].# Split every morning
            'when': 'MIDNIGHT'.Store for 30 days
            'backupCount': 30,}},'loggers': {
        'django': {
            'handlers': ['console'].'level': 'ERROR'.'propagate': False
        },
        'web.log': {
            'handlers': ['restful_api'].'level': 'INFO'.Messages processed by this logger are not processed again by the Django logger
            'propagate': False}}},Copy the code

In this way, any request that goes through Django will be logged, either on the Web or by Django admin. Records which fields can be obtained and configured based on project requirements.

It is important to note that obtaining the user name from request.user only applies to session authentication, because session authentication assigns the user name to Request. user.

Request. user has no value, assuming JWT authentication. There are two ways to obtain a username: One is to parse the JWT cookie in the logging middleware to get the user name, but this is not a good way. A better way is to override the JWT authentication and assign the user name to Request. user so that request.user can be called anywhere else.

That’s all you need to know about logging in Django. I hope you keep your logs in mind, because you’ll definitely need them.

Reference Documents:

Docs.djangoproject.com/en/2.1/topi…

www.dusaiphoto.com/article/det…

Juejin. Cn/post / 684490…

www.xiaomastack.com/2019/01/11/…