django: 例外(exception)をログに残すようにする

TLDR

djangoは開発モード(DEBUG=True)でリクエストの詳細やスタックトレースを含む美しいデバッギング情報をブラウザに返す。しかし本番モード(DEBUG=False)だとアプリケーション(views)からの例外は残らないようだ。ディフォルトのエラーハンドラーをオーバライドするこによって例外をログに残すことができる。

hander500をオーバライドする

# 組み込みの500エラーハンドラーを自前のにすり替える。

# urls.pyでやるのがいいだろう。

# 参照： http://docs.djangoproject.com/en/dev/topics/http/views/

from django.conf.urls.defaults import *

handler500=exception_logger.server_error'

exception_logger.py

import sys,os

import traceback

from datetime import * 

from time import mktime

from django.views.defaults import server_error as default_server_error
def server_error(request, *args, **kw):

    """ djangoのディフォルトエラーハンドラー

	django.conf.urls.defaults.server_error

	の代わりに500エラーを処理する。DEBUG==Falseの場合のみ。

	詳細をログに書き、ブラウザへの返答はジャンゴに任せる。

	使い方： 以下のコードをurls.pyなどに入れる。

        handler500='ext.exception_logger.server_error' 

    """

    # 開発モードでブラウザに送られるリスポンスオブジェクトを作る。

    from django.views import debug

    exc_info = sys.exc_info()

    rsp=debug.technical_500_response(request, *exc_info)
    # ログファイル名： path-to-view.timestamp.html

    dumpfile='.'.join([request.path_info.lstrip('/').rstrip('/').replace('/','-'), str(int(mktime(datetime.now().timetuple()))), 'html'])

    dumppath=os.path.join(/var/tmp/myapp-crash-log', dumpfile)
    # リスポンスからHTMLを取り出してログファイルに出力。

    open(dumppath,'w').write(rsp.content)
    # ブラウザへの返答はジャンゴに任せる。(500.htmlテンプレートでページを作って返す)

    return default_server_error(request, *args, **kw)

既存のハンドラーを組み合わせて詳細をログに残す

本番モードでも例外の詳細をログに書き込むようにしているだけ。エラーメッセージの生成をジャンゴにやらせているので、ログの出力操作をするだけですんじゃう。 django.core.handlers.handle_uncaught_exceptionの最後に詳細を保存するロジックを差し込んだことになる。 (上のコードは自分で使っているものをブログ用に浄化したものでそのまま走らせて検証はしていないので、もし壊れていたらコメントで叱ってくださ。)

もし簡潔なテキスト情報をログに出したいときは

extype, exval, tbk = sys.exc_info()

stackframe_list=traceback.format_tb(tbk)

logging.error(extype, exval, stackframe_list)

使ってみて

ログに大きなhtmlファイルを残すっていうのは標準的なやりかたじゃない。でも、トレースやリクエストの詳細などを見易いテキストに書換える関数を書いているうちにバカらしくなって止めた。だってジャンゴがすでに綺麗なページを作ってくれるんだもん。ブラウザでHTMLログファイルを開けてみたら、開発時と同じ例外画面が。とても快適だ。これは新しい遠隔デバッギングのスタイルになるかもしれない。

サイズについて

バカでかいログファイルを作ってしまうのが気になるが、「例外」っていうからにはあまり起きないのが前提だ。htmlファイルの殆どは雛型情報なので、圧縮すれば1/10とかになると思う。万一、例外が大量発生した場合を考えて、過去N個しか残さないような仕組にした方が安全かも。あるいは専用のログパーティションに書き込むとか。

何でこの機能が組込まれていないの？

本番モードでアプリケーションの例外をログに残さないってのは不可解な設計だ。プロダクションでページがコケたらログでそれを見付けて直すのが普通の流れだと思う。他のフレームワークでも開発環境ではブラウザにスタックトレースを、本番環境ではログにってのが普通だと思う。何でジャンゴはそうしないのか？以前のこのようなエラー情報の扱いを見たことがある。htmlデザインから aspやphpに卒業していったウェブ開発者はインタラクティブなデバッグ情報を綺麗に見せる画面を作る。しかし、それをログに残すことを考えていない。インタラクティブなウェブ開発指向の考えだ。一方unixのバックグラウンドの開発者は、サーバは非対話的に動いているとういのが前提なので、まずエラーをログに書くようにする。画面に返すエラーは殺風景なものですませる。対話的 vs 非対話的なバックグラウンドの違いからくるものだろう。