美文网首页
Django搭建个人博客:日志记录

Django搭建个人博客:日志记录

作者: 杜赛_dusai | 来源:发表于2019-07-17 23:46 被阅读0次

    上一章学习了自动化测试,很好,现在我们可以绞尽脑汁写出一份全面的测试,来保证代码永远健康了。

    话虽如此,但是作为一个独立开发者很难写出真正全面的测试代码。这是因为用户在使用你的网站时可不会循规蹈矩,而是会以各种怪异的姿势浏览网页、上传数据。但这也不是坏事,用户就是天然的测试人员,他们会很可爱的帮你找出一大堆的bug,陪你度过难眠的夜晚(伴随着编程能力的提升)。

    现在的问题是,开发者如何得知用户到底遇到了哪些问题?用户们大部分都与你素昧平生,分部在世界各地。更糟糕的是,部署在线上时由于配置了DEBUG = False,出错时并不会出现报错页面,连用户自己都不清楚到底是哪里有bug。

    Django给你的答案:日志

    日志的组成

    日志是指程序在运行过程中,对状态、时间、错误等的记录。即把运行过程中产生的信息输出或保存起来,供开发者查阅。

    Django使用Python内置的logging模块处理日志。关于该模块的使用,Python文档里有非常详细的讨论。如果你从未用过,本文提供一个快速入门。

    日志事件的信息流程如下:

    image

    这个图看不懂也没关系。以后你需要深度使用日志时,会回来仔细研究它的。

    一份日志配置由LoggersHandlersFiltersFormatters四部分组成。

    Loggers

    Logger记录器,是日志系统的入口。它有三个重要的工作

    • 向应用程序(也就是你的项目)公开几种方法,以便运行时记录消息
    • 根据传递给Logger的消息的严重性,确定出需要处理的消息
    • 将需要处理的消息传递给所有感兴趣的处理器(Handler

    每一条写入logger的消息都是一条日志记录。每一条日志记录也包含级别,代表对应消息的严重程度。常用的级别如下:

    • DEBUG:排查故障时使用的低级别系统信息,通常开发时使用
    • INFO:一般的系统信息,并不算问题
    • WARNING:描述系统发生的小问题的信息,但通常不影响功能
    • ERROR:描述系统发生的大问题的信息,可能会导致功能不正常
    • CRITICAL:描述系统发生严重问题的信息,应用程序有崩溃风险

    当logger处理一条消息时,会将自己的日志级别和这条消息的日志级别做对比。如果消息的级别匹配或者高于logger的日志级别,它就会被进一步处理;否则这条消息就会被忽略掉。

    当logger确定了一条消息需要处理之后,会把它传给Handler

    Handlers

    Handler处理器,它的主要功能是决定如何处理logger中每一条消息,比如把消息输出到屏幕、文件或者Email中。

    和logger一样,handler也有级别的概念。如果一条日志记录的级别不匹配或者低于handler的日志级别,则会被handler忽略。

    一个logger可以有多个handler,每一个handler可以有不同的日志级别。这样就可以根据消息的重要性不同,来提供不同类型的输出。例如,你可以添加一个handler把ERRORCRITICAL消息发到你的Email,再添加另一个 handler把所有的消息(包括ERRORCRITICAL消息)保存到文件里。

    Filters

    Filter过滤器。在日志记录从logger传到handler的过程中,使用Filter做额外的控制。例如只允许某个特定来源的ERROR消息输出。

    Filter还被用来在日志输出之前对日志记录做修改。例如当满足一定条件时,把日志记录从 ERROR 降到 WARNING 级别。

    Filter在logger和handler中都可以添加;多个filter可以链接起来使用,来做多重过滤操作。

    Formatters

    Formatter即格式化器,主要功能是确定最终输出的形式和内容

    日志配置示例

    说了这么多脑壳都说晕了,接下来看两个示例。

    简单示例

    在Django中可以通过字典的形式对整个项目的日志进行配置,配置的位置当然是在settings.py中了。一个简单的配置如下:

    my_blog/settings.py
    
    ...
    import os
    
    LOGGING = {
        'version': 1,
        'disable_existing_loggers': False,
        'handlers': {
            'file': {
                'level': 'DEBUG',
                'class': 'logging.FileHandler',
                'filename': os.path.join(BASE_DIR, 'logs/debug.log'),
            },
        },
        'loggers': {
            'django': {
                'handlers': ['file'],
                'level': 'DEBUG',
                'propagate': True,
            },
        },
    }
    

    字典中的version指明了配置的版本;disable_existing_loggers指明是否禁止默认配置的记录器。这两项通常不需要去改动,重点看下loggershandlers的配置:

    • 如前面说,一条消息首先传递给logger。Django中内置了几种记录器,比如这里用到的Django记录器,它会接收Django层次结构中的所有消息。然后我们定义了需要处理DEBUG以上级别的消息,并把这些消息传递给名叫file的处理器。'propagate': True意思是本记录器处理过的消息其他处理器也可以继续处理。
    • 现在消息来到名叫filehandlers中了。这个处理器定义了消息处理级别仍然为DEBUG,在class中定义将消息输出到文件中去,文件地址为项目目录的logs/debug.log
    • 因为这里没有配置filtersformatters,因此会采用默认的设置。

    需要注意的是日志的输出文件的目录logs/一定要提前创建好,并且确保项目拥有此目录的写入权限。

    这个日志系统就配置好了!接下来运行项目,随便刷新几个页面看看debug.log中有没有写入消息:

    logs/debug.log
    
    (0.001) 
                SELECT name, type FROM sqlite_master
                WHERE type in ('table', 'view') AND NOT name='sqlite_sequence'
                ORDER BY name; args=None
    (0.000) SELECT "django_migrations"."app", "django_migrations"."name" FROM "django_migrations"; args=()
    ...
    ...
    ...
    

    debug.log文件中出现了一大堆冗长的信息,因为DEBUG级别会包含所有的数据库查询记录。

    默认情况下,仅在调试模式下才会显示DEBUG级别的消息日志,部署在线上时只会将INFO或以上的信息进行记录。

    再试试别的。把上面代码中记录器和处理器的日志级别都改为INFO

    LOGGING = {
        ...
        'handlers': {
            'file': {
                'level': 'INFO',
                ...
            },
        },
        'loggers': {
            'django': {
                'level': 'INFO',
                ...
            },
        },
    }
    

    再刷新几次界面,看看输出的内容:

    "GET /article/article-list/ HTTP/1.1" 200 14438
    "GET /article/article-detail/32/ HTTP/1.1" 200 33364
    "GET /accounts/login/ HTTP/1.1" 200 7180
    ...
    

    这次清爽多了,输出的主要是页面的拉取信息。

    让我们再看看ERROR信息长什么样的。在地址栏输入一个不存在的文章详情页面地址:

    http://127.0.0.1:8000/article/article-detail/9999/
    

    很明显这会得到一个数据不存在的报错:

    Internal Server Error: /article/article-detail/9999/
    Traceback (most recent call last):
      File "E:\django_project\env\lib\site-packages\django\core\handlers\exception.py", line 34, in inner
        response = get_response(request)
        ...
    article.models.ArticlePost.DoesNotExist: ArticlePost matching query does not exist.
    "GET /article/article-detail/9999/ HTTP/1.1" 500 80792
    

    ERROR日志输出了整个bug的回溯,和你在浏览器中的报错是完全一样的,这些信息就非常的有用了。基本上ERROR信息能够暴露出用户在使用你的网站过程中的大部分问题;也就是说每一个ERROR都是需要你去解决掉的。ERROR信息的错误码通常都是“500”,也就是服务器内部错误的代码。

    不过仔细想想,似乎找不到对应的资源在很多时候并不是bug,而是用户在输入url时自己犯了错误。所以我们把文章详情视图的ArticlePost.objects.get(id=id)改成get_object_or_404(ArticlePost, id=id)试试:

    article/views.py
    
    ...
    from django.shortcuts import get_object_or_404
    
    def article_detail(request, id):
        # 取出相应的文章
        # article = ArticlePost.objects.get(id=id)
        article = get_object_or_404(ArticlePost, id=id)
    
        ...
    

    服务器重启后再次刷新一个不存在的页面,看看日志:

    Not Found: /article/article-detail/9999/
    "GET /article/article-detail/9999/ HTTP/1.1" 404 1780
    

    现在它不是一条ERROR信息了,而是变为了WARNING,所以也没有了错误回溯(错误码也由 500 变成了 404)。这里就能看出这两个方法的重要区别了;在项目中到底选择哪个没有定论,还是以你的具体需求决定。

    复杂示例

    接下来再看一个复杂的日志配置:

    LOGGING = {
        'version': 1,
        'disable_existing_loggers': False,
        'formatters': {
            'verbose': {
                'format': '{levelname} {asctime} {module} {process:d} {thread:d} {message}',
                'style': '{',
            },
            'simple': {
                'format': '{levelname} {message}',
                'style': '{',
            },
        },
        'filters': {
            'require_debug_true': {
                '()': 'django.utils.log.RequireDebugTrue',
            },
        },
        'handlers': {
            'console': {
                'level': 'INFO',
                'filters': ['require_debug_true'],
                'class': 'logging.StreamHandler',
                'formatter': 'simple'
            },
            'mail_admins': {
                'level': 'ERROR',
                'class': 'django.utils.log.AdminEmailHandler',
                'formatter': 'verbose',
            },
            'file': {
                'level': 'WARNING',
                'class': 'logging.FileHandler',
                'filename': os.path.join(BASE_DIR, 'logs/debug.log'),
                'formatter': 'verbose',
            },
        },
        'loggers': {
            'django': {
                'handlers': ['console'],
                'propagate': True,
            },
            'django.request': {
                'handlers': ['file', 'mail_admins'],
                'level': 'WARNING',
                'propagate': False,
            },
        }
    }
    

    让我们来分解一下此配置。

    配置中定义了两个格式化器

    • verbose:详细的格式化器,依次输出:消息级别、发生时间、抛出模块、进程ID、线程ID、提示信息
    • simple:简要的格式化器,仅输出消息级别和提示信息

    一个过滤器

    • require_debug_true:使用此过滤器的消息仅在调试时才会生效

    三个处理器

    • console:处理INFO以上级别消息,输出简要信息到命令行中;此处理器仅在调试模式生效
    • mail_admins:处理ERROR以上级别消息,输出详细信息到Email中
    • file:处理WARNING以上级别消息,输出详细信息到文件中

    两个记录器

    • django:将django产生的所有消息转交给console处理器
    • django.request:将网络请求相关消息转交给filemail_admins这两个处理器。注意这里的'propagate': False使得此记录器处理过的消息就不再让django记录器再次处理了

    读者可以尝试制造不同级别的消息,看看日志系统是否正常工作。当然最重要的,跟Email有关的配置一定要事先把Email给设置好,即下面的内容填成你的:

    # SMTP服务器
    EMAIL_HOST = 'your smtp'
    # 邮箱名
    EMAIL_HOST_USER = 'your email'
    # 邮箱密码
    EMAIL_HOST_PASSWORD = 'your password'
    # 发送邮件的端口
    EMAIL_PORT = 25
    # 是否使用 TLS
    EMAIL_USE_TLS = True
    # 默认的发件人
    DEFAULT_FROM_EMAIL = 'your email'
    

    日志分割

    现在我们已经可以愉快的记录日志了,接下来一个问题是如何去分割日志?假设你的网站能够有幸运行十年时间,如果不间断的往同一个文件中写日志信息,最终它会变成一个拖垮服务器的庞然大物。

    最好是日志能够按自然天进行记录和分割。好在这个问题也不需要你去费脑筋,Python帮你搞定了。

    只需要把处理器稍稍改一下:

    my_blog/settings.py
    
    ...
    LOGGING = {
        ...
        'handlers': {
            ...
            'file': {
                ...
                # 注释掉 class
                # 'class': 'logging.FileHandler',
                
                #新增内容
                'class': 'logging.handlers.TimedRotatingFileHandler',
                'when': 'midnight',
                'backupCount': 30,
                
            },
        },
        ...
    }
    
    • TimedRotatingFileHandler:Python内置的随时间分割日志文件的模块
    • when:分割时间为凌晨
    • backupCount:日志文件保存日期为30天

    接下来把系统时间往后调一天,然后重新启动服务器:

    python manage.py runserver --noreload
    

    注意这次启动有点不一样,后面有个--noreload后缀。这是因为通常Django的调试服务器运行时会顺带启动重载器,所以每当重载器检测到代码有变化后,会自动重启服务器,相当的方便。但问题是分割文件与重载器同时操作日志文件会产生冲突,因此这里一定要用--noreload暂时将重载器禁止掉。

    然后就可以愉快的刷几条消息到文件中啦。你会发现老日志已经更名为debug.log.2019-07-17了,而刚刷的新消息则保存在debug.log中。

    除了上面介绍的TimedRotatingFileHandler,Python还提供了一个按照文件大小分割的RotatingFileHandler。有兴趣的看Python官方文档

    自定义日志

    内置配置实际上已经能够满足90%以上的日志需求了,但总有时候你想在一些奇怪的地方进行记录,这就需要你自己在代码中插入自定义的日志记录代码了。

    自定义日志用起来也是相当方便的:

    from my_blog.settings import LOGGING
    import logging
    
    logging.config.dictConfig(LOGGING)
    logger = logging.getLogger('django.request')
    
    def whatever(request):
        # do something
        logger.warning('Something went wrong!')
        # do something else
    

    导入刚才写的日志框架并将django.request配置到logger对象中。然后你就可以在任何地方安插任何级别的消息了。消息内容可以用字符串的格式化方法(str.format()),玩出各种花样。

    关于日志的入门介绍就到此为止了,想深入学习的读者请继续阅读本文的参考文章:

    总结

    和上章类似,本章的内容也是概念偏多,希望读者尽可能去理解,最起码要囫囵吞枣的把日志成功移植到你的项目中去。获取一份好的日志,有时候远比开发一个无关紧要的新功能更重要。

    比较起来博主认为对博客项目来说,日志比测试还重要,毕竟用户的使用体验是最佳的实践。

    但请不要误会我的意思。测试和日志就像两兄弟,测试解决开发中的问题,日志解决维护中的问题。有机的结合起来,你的项目才能够长期稳定健康。


    相关文章

      网友评论

          本文标题:Django搭建个人博客:日志记录

          本文链接:https://www.haomeiwen.com/subject/psvhlctx.html