Django 打造 logging handler 將 exception 送到 Slack

Posted on Sep 22, 2018 in Django by Amo Chen ‐ 4 min read

覺得我們的內容實用嗎？ MyApollo 電子報讀者募集中！歡迎訂閱電子報!

Django 整合 Python 內建的 logging 作為 logging system ，所以能夠很簡單地新增客製化的 logging handler ，例如官方提供 AdminEmailHandler 可以將 exception 寄到 admin 信箱。

本文介紹如何打造可以將 exception 送到 Slack 的 logging hander 。

本文環境：

Python 3.6.5
Django 2.1.1
slackclient 1.3.0

開始本文之間請先用以下指令建立一個 Django project ：

$ django-admin startproject playground
$ cd playground
$ touch logging_handlers.py
$ django-admin startapp app

整個專案結構為：

.
├── app
│   ├── __init__.py
│   ├── admin.py
│   ├── apps.py
│   ├── migrations
│   │   └── __init__.py
│   ├── models.py
│   ├── tests.py
│   └── views.py
├── logging_handlers.py
├── manage.py
└── playground
    ├── __init__.py
    ├── settings.py
    ├── urls.py
    └── wsgi.py

本文只會修改其中的 logging_handlers.py , app/views.py , playground/settings.py ，如果不懂其他檔案的用途，建議詳閱 Django 的相關文件。

在動手前先談談 logging system 的運作， logging system 有 4 個主要的角色：

Loggers
Filters
Handlers
Formatters

每個角色都各司其職， loggers 作為進入點負責將訊息轉到 logging system 等待後續處理，而 filters 則負責過濾哪些訊息要交給哪個 handlers , handlers 則負責將從 logging system 接收到的訊息進行處理，例如將訊息寫到檔案、利用 email 寄出等，而 formatters 則如其名負責最後輸出訊息的格式。

以上 4 個角色各司其職，完成整個 logging system 所負責的事情。

所以要將 exception 送至 Slack 的話，很明顯會由 handler 負責。接著，就在 logging_handlers.py 中撰寫客製化的 handler 吧！

SlackAdminHandler

撰寫 handler 的方法很簡單，只要繼承 logging.Handler 並實作 emit(record) 方法即可，所以基礎架構如下：

# -*- coding: utf-8 -*-
import logging


class SlackAdminHandler(logging.Handler):
    def emit(self, record):
        pass

emit 的參數 record 通常為 Python LogRecord instance, 該 instance 會包含 loggin level (如 DEBUG, INFO, ERROR 等), log 時間, stack trace info 以及 log message 等等，可以視情況需要添加到 log 中。

然而 Django 是 web framework, 所以有時候會需要關注發生 exception 時的 request 存些什麼資訊，例如可能是使用者輸入未預期的資料造成例外情況(exception)，因此 Django 在有 request 時會將 request 附加到 LogRecord 之中，可以透過 record.request 取得 Django request 資訊，以下將透過 record.request 取得 Django request 並將 request 中的 IP 位址及 request path 與 request body 寄至 Slack 的 handler 方便後續進行除錯。

p.s. 此處 record.request 其實是 WSGIRequest instance, 並非 HttpRequest

不過 record.request 並不是絕對會出現的屬性，所以在 handler 中需要額外判斷該屬性是否存在，因此結合 request instance 內的資料與 record 原有的資料後，上述的 handler 程式可以進一步變成：

# -*- coding: utf-8 -*-
import logging

from django.conf import settings


class SlackAdminHandler(logging.Handler):
    def emit(self, record):
        levelname = record.levelname
        message = record.getMessage()
        request = getattr(record, 'request', None)
        ip_addr = method = path = body = ''

        if request:
            method = request.method
            path = request.path
            body = request.body

            ip_addr = request.META.get('REMOTE_ADDR', '')
            if ip_addr in settings.INTERNAL_IPS:
                ip_addr = f'{ip_addr} (internal ip)'
            else:
                ip_addr = f'{ip_addr}'

取得需要的資訊後，下一步就是將這些資訊送往 Slack 。

將資訊送往 Slack 需要建立一個 bot ，請先按照 Enabling interactions with bots 建立好 Slack bot 並取得 API token 。

接著結合 slackclient 加上寄送的功能(程式細節就不再贅述)：

# -*- coding: utf-8 -*-
import os
import logging

from slackclient import SlackClient

from django.conf import settings
from django.core.handlers.wsgi import WSGIRequest


_SLACK_BOT_TOKEN = os.environ.get('SLACK_BOT_TOKEN')
_SLACK_BOT = SlackClient(_SLACK_BOT_TOKEN)


class SlackAdminHandler(logging.Handler):
    def emit(self, record):
        request = getattr(record, 'request', None)
        ip_addr = ''
        method = ''
        path = ''
        body = ''
        if isinstance(request, WSGIRequest):
            ip_addr = request.META.get('REMOTE_ADDR', '')
            if ip_addr in settings.INTERNAL_IPS:
                ip_addr = f'{ip_addr} (internal ip)'
            else:
                ip_addr = f'{ip_addr}'

            method = request.method
            path = request.path
            body = request.body

        levelname = record.levelname
        message = record.getMessage()

        _SLACK_BOT.api_call(
            'chat.postMessage',
            channel='#general',  # or your admin channel
            text=(
                f'[{levelname}] {ip_addr} {method} {path}\n'
                f'{body}\n'
                f'{message}\n'
            )
        )

以上就完成 handler 囉！

添加 logging 設定到 settings.py

完成 handler 後，需要將 logging handler 的設定添加到 settings.py 中才能運作。

Django 文件提供的 logging 設定範例如下：

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'file': {
            'level': 'DEBUG',
            'class': 'logging.FileHandler',
            'filename': '/path/to/django/debug.log',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['file'],
            'level': 'DEBUG',
            'propagate': True,
        },
    },
}

簡而言之，上述設定註冊一個名稱為 django 的 logger ，該 logger 會紀錄的 level 是 DEBUG 層級的訊息，而負責處理的 handlers 為 file ，剛好對應回 handlers dictionary 底下的 file dictionary 。

而 'propagate': True 代表訊息還會傳遞給其他更高級別的其他 loggers / handlers 處理。

If this attribute evaluates to true, events logged to this logger will be passed to the handlers of higher level (ancestor) loggers, in addition to any handlers attached to this logger. Messages are passed directly to the ancestor loggers’ handlers - neither the level nor filters of the ancestor loggers in question are considered.

而我們目前只有一個 handler ，而且我們所感興趣的 logging level 只有 ERROR ，所以將範例改寫成為：

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'handlers': {
        'slack': {
            'level': 'ERROR',
            'class': 'logging_handlers.SlackAdminHandler',
        },
    },
    'loggers': {
        'django': {
            'handlers': ['slack'],
            'level': 'ERROR',
            'propagate': True,
        },
    },
}

接著將上述設定貼回到 settings.py 中。

測試

Handler 與設定都準備好之後，就該輪到測試是否正常運作了。打開 app/views.py 貼上以下程式，模擬首頁爆炸的情況，測試是否會真的寄到 Slack 中：

# -*- coding: utf-8 -*-
from datetime import datetime
from django.http.response import HttpResponse


def current_datetime(request):
    now = datetime.now()
    raise ValueError
    html = "<html><body>It is now %s.</body></html>" % now
    return HttpResponse(html)

測試之前，記得將 playground/urls.py 改寫，以將 request 導至 current_datetime view function 中處理：

from django.contrib import admin
from django.urls import path
from app.views import current_datetime


urlpatterns = [
    path('', current_datetime),
]

最後以下指令執行測試 server ，並以瀏覽器打開 http://127.0.0.1:8000/ 測試是否會收到 Slack 訊息：

$ python manage.py runserver

正確執行的話將會在 Slack #general channel 看到以下畫面：

p.s. 上述畫面中的 Internal Server Error: / 及以下字串其實就是 record.getMessage() 的內容。

總結

至此，已學會 Python logging system 的基礎概念，以及如何自製 Django logging handler 的方法。

但此 logging handler 仍屬粗糙，還有許多地方可以改善，例如加入其他對除錯更方便的 exception info ，以及錯誤情形大量發生時，要如何控制送往 Slack 的訊息量，避免轟炸開發人員，因此若要作為可以執行在 production 環境的 logging handler 來說還是不成熟，但相信本文能為有類似需求的開發者們開啟一道方便法門。

以上， Happy Coding!

References

https://github.com/django/django/blob/master/django/core/handlers/wsgi.py

https://docs.djangoproject.com/en/2.1/topics/logging/#topic-logging-parts-handlers

https://docs.python.org/3/library/logging.html#module-logging

覺得我們的內容實用嗎？ MyApollo 電子報讀者募集中！歡迎訂閱電子報!

django python logging slack

Django 打造 logging handler 將 exception 送到 Slack

SlackAdminHandler

添加 logging 設定到 settings.py

測試

總結

References

對抗久坐職業傷害

贊助我們的創作

Django 打造 logging handler 將 exception 送到 Slack

SlackAdminHandler #

添加 logging 設定到 settings.py #

測試 #

總結 #

References #

對抗久坐職業傷害

贊助我們的創作

你可能也會感興趣的文章

Django 驗證 email

Django 整合 jinja 2

Django Extending the Existing User model

SlackAdminHandler

添加 logging 設定到 settings.py

測試

總結

References