fortune/README.md

## README.md

      
    Raw
  

              README.md
            
          
    Python ロギング方法

Python 組み込みの logging モジュールを使う。
logging — Python 用ロギング機能
Logging HOWTO
Good logging practice in Python
構成要素


logging.Logger
logging.Handler
logging.Formatter
logging.Filter


Logger はロギングシステムのエントリポイント。ここに debug や error 等のメソッドを使ってログメッセージを送り込む。
メソッドごとに対応するログレベルがあり、それが Logger 自身のログレベル以上なら処理され、未満なら無視される。
Handler は、ログメッセージをどう処理するか、すなわち、ファイルに書き込むか、ソケットに送るかなどを決定するエンジン。
Logger は Handler を複数もつことができ、ログメッセージを Handler に送り込む。Handler 自身もログレベルをもっており、
ログメッセージのログレベルがそれ未満ならば無視する。
Formatter は Handler にセットされ、メッセージのフォーマット方法を決める。
Filter は Logger や Handler に設定される。ログレベルでは間に合わないようなフィルタリングをする。たとえば、
特定のソースから発生したログのみを対象にしたりとか。
Logger は階層構造をもつ。root Logger が頂点にあり、. で区切られた名前で階層関係を定義する。モジュールごとに
Logger を分けるのが推奨されるやり方なので、
import logging

logger = logging.getLogger(__name__)
とするのがよい。
>>> import logging
>>> 
>>> root = logging.getLogger()      # 引数なしだと root Logger を取得する。
>>> root
<RootLogger root (WARNING)>         # root Logger のデフォルトのログレベルは warning だ。
>>> 
>>> l1 = logging.getLogger('foo.bar')
>>> l1
<Logger foo.bar (WARNING)>          # 自分で設定しないと、親のログレベルを受け継ぐ。
>>> 
>>> l1 is logging.getLogger('foo.bar')  # 同じ名前の Logger はシングルトンである。
True
>>> 
>>> 
>>> l = logging.getLogger('foo')    # 'foo.bar' の親となる Logger
>>> l
<Logger foo (WARNING)>
>>> 
>>> 
>>> import logging_tree     # ロギング設定を表示するための Third party モジュール
>>> 
>>> logging_tree.printout()
<--""
   Level WARNING
   |
   o<--"foo"
       Level NOTSET so inherits level WARNING
       |
       o<--"foo.bar"
           Level NOTSET so inherits level WARNING
ここでは、Logger のツリー構造と設定を調べるための Third party モジュール logging_tree を使った。
Logger オブジェクトがログメッセージを自分が持っている Handler に送り込むとき、同時に親 Logger にも伝搬させる。propagate プロパティを
False にすると伝搬しない（デフォルトは True）。したがって、ログメッセージが重複して出力されることがありうる。そうしたくないのであれば、
root Logger あるいは、アプリケーションのトップモジュールに対応した Logger にのみ Handler をセットし、その子である Logger はメッセージを
親へと伝搬させるだけにするというのが、典型的なシナリオだ。
プログラマブルなロギング設定

Python コード中で、Logger や Handler のオブジェクトを作成し、設定して使うことができる。例えば次のようにする。
import logging
 
>str_handler = logging.StreamHandler()
file_handler = logging.FileHandler('myapp.log')

formatter = logging.Formatter(fmt='%(asctime)s [%(levelname)s] %(name)s: %(message)s', datefmt='%Y-%m-%d %H:%M:%S %Z')

str_handler.setFormatter(formatter)
file_handler.setFormatter(formatter)

logger = logging.getLogger(__name__)
logger.addHandler(str_handler)
logger.addHandler(file_handler)
logger.setLevel(logging.INFO)

from logging_tree import printout


printout()
<--""
   Level WARNING
   |
   o<--"__main__"
       Level INFO
       Handler Stream <_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>
         Formatter fmt='%(asctime)s %(levelname)s : %(message)s' datefmt='%Y-%m-%d %H:%M:%S %Z'
       Handler File '/Users/kazu/Documents/samples/django_samples/django_logging/myapp.log'
         Formatter fmt='%(asctime)s %(levelname)s : %(message)s' datefmt='%Y-%m-%d %H:%M:%S %Z'

logger.info('hello')
2019-03-08 17:55:14 JST [INFO] __main__: helo    # コンソール�と同時に myapp.log ファイルにも書き込まれる。
Logger オブジェクトに送り込まれたログメッセージがログレベル等のために無視されることなく、しかし、どの Handler にも送り込まれなかった場合、
logging.lastResort に入っている Handler に送り込まれる。これはデフォルトでは、sys.stderr に何らフォーマットされることなく出力される。
https://docs.python.jp/3/howto/logging.html#what-happens-if-no-configuration-is-provided
単純なアプリケーションであれば、トップレベルのモジュールで root Logger の設定だけをし、各モジュールの Logger ではログメッセージを上に
伝搬させるだけでよいかもしれない。root Logger の設定をするには、logging モジュールの basicConfig 関数 を使えばいい。
宣言的なロギング設定

logging.config モジュールの関数を使う。
logging.config.dictConfig 関数を使うなら、設定を記述した辞書を渡す。以下は、後述する Django のデフォルトのロギング設定を取り消して再定義すると同時に自分のアプリケーションのロギング設定をしたときに使った辞書。

{
    'version': 1,
    'disable_existing_loggers': False,

    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },

    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'style': '{',
        },

        'api_console': {
            'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S %Z',
        },
    },

    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },
        'django.server': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'django.server',
        },
        'console_for_mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },

        'api_console': {
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },
    },


    'loggers': {
        'django': {
            'handlers': ['console', 'console_for_mail_admins'],
            'level': 'INFO',
        },
        'django.server': {
            'handlers': ['django.server'],
            'level': 'INFO',
            'propagate': False,
        },

        'api': {
            'level': LOGLEVEL,
            'handlers': ['console'],
            'propagate': False,
        },
    },
}
formatters, handlers, loggers というキーで、それぞれ Formatter, Handler, Logger を定義している。
ライブラリのためのロギング設定

Django でのロギング設定

Django はライブラリでなくフレームワークであるわけだが、デフォルトのロギング設定 をしている。
この設定は、logging_tree モジュールを利用して確認できる。
たとえば、Django Tutorial のプロジェクトで
$ python manage.py shell

のように Django をシェルで起動して、
>>> from logging_tree import printout
>>> 
>>> 
>>> printout()
<--""
   Level WARNING
   |
   o<--"django"
       Level INFO
       Handler Stream <_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>
         Level INFO
         Filter <django.utils.log.RequireDebugTrue object at 0x105ede9b0>
       Handler <AdminEmailHandler (ERROR)>
         Level ERROR
         Filter <django.utils.log.RequireDebugFalse object at 0x105eefb70>
       |
       o<--[django.db]
       |   |
       |   o<--"django.db.backends"
       |       Level NOTSET so inherits level INFO
       |       |
       |       o<--"django.db.backends.schema"
       |           Level NOTSET so inherits level INFO
       |
       o<--"django.request"
       |   Level NOTSET so inherits level INFO
       |
       o<--[django.security]
       |   |
       |   o<--"django.security.csrf"
       |       Level NOTSET so inherits level INFO
       |
       o   "django.server"
       |   Level INFO
       |   Propagate OFF
       |   Handler Stream <_io.TextIOWrapper name='<stderr>' mode='w' encoding='UTF-8'>
       |     Level INFO
       |     Formatter <django.utils.log.ServerFormatter object at 0x105d86320>
       |
       o<--"django.template"
           Level NOTSET so inherits level INFO
>>> 
Django のロギング設定を確認できる。django Logger を見てみると、Filter が設定してあり、これにより、settings.DEBUG によって
振る舞いを変えていることがわかる。
settings.LOGGING にここ のような辞書をセットすると、それでロギングを設定してくれる。辞書中の disable_existing_loggers キーは、既存のロギング設定を無効にするかどうかを指定する。True(デフォルト）だと、無効になるので注意しないといけない。基本、ここは False にした方がいい。
Django のデフォルトのロギング設定を無効にしたいなら、settings.LOGGING_CONFIG を None に設定する。これはあくまでロギングの設定を
無効にするだけであって、Django のコード中のロギング呼び出しが無効になるわけではない。また、こうすると、settings.LOGGING に辞書を設定してもそれを自動で設定してはくれなくなるので、明示的に logging.config.dictConfig 関数を呼び出さなくてはならない。これは settings モジュール中でできる。
もしくは、apps.py 中の AppConfig のサブクラスの ready メソッド内で dictConfig 関数を呼び出してもいい。ready メソッドは、Django アプリケーションの開始時に一回だけ実行される。
Django におけるロギング設定は、Django Logging, The Right Way の
記事が参考になる。
Django でのロギング設定のサンプル

Django のデフォルト設定を再定義し、自分のアプリケーションの設定を settings モジュール中で実行した。__main__ という Logger を設定していることに注意。これは、Django アプリケーションではなく、Django の settings 設定等を利用するスクリプトとして起動するモジュールのためのもの。スクリプトとして起動されるモジュールの __name__ は __main__ になるのでこうする必要があるのだ。
#
# Django のデフォルトのロギング設定を無効にして、api モジュールアプリと一緒に
# 一から設定し直す。
#
# django.server Logger のふるまいはデフォルトと変わらない。
#
# django Logger は、DEBUG = True のときも False のときも
# api モジュールで定義されているアプリケーションと同一の formatter を使うようにしている。
# こうすれば api アプリケーションと同じやり方でログ解析できる（そもそもデフォルトのフォーマットは
# 解析しにくいように思える）。また、E メールでログ出力するのはやめ、常にコンソールに出力するように
# している。
#
# ログは常にコンソールへ出力するようにして、後の処理は、Docker や、その他のログ管理システム等に
# まかせる。
#
# api および、__main__ のログレベルは、環境変数 LOGLEVEL で指定する。デフォルトは INFO。
#
LOGGING_CONFIG = None
LOGLEVEL = os.environ.get('LOGLEVEL', 'info').upper()
logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': False,

    'filters': {
        'require_debug_false': {
            '()': 'django.utils.log.RequireDebugFalse',
        },
        'require_debug_true': {
            '()': 'django.utils.log.RequireDebugTrue',
        },
    },

    'formatters': {
        'django.server': {
            '()': 'django.utils.log.ServerFormatter',
            'format': '[{server_time}] {message}',
            'style': '{',
        },

        'api_console': {
            'format': '%(asctime)s [%(levelname)s] %(name)s: %(message)s',
            'datefmt': '%Y-%m-%d %H:%M:%S %Z',
        },
    },

    'handlers': {
        'console': {
            'level': 'INFO',
            'filters': ['require_debug_true'],
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },
        'django.server': {
            'level': 'INFO',
            'class': 'logging.StreamHandler',
            'formatter': 'django.server',
        },
        'console_for_mail_admins': {
            'level': 'ERROR',
            'filters': ['require_debug_false'],
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },

        'api_console': {
            'class': 'logging.StreamHandler',
            'formatter': 'api_console',
        },
    },


    'loggers': {
        'django': {
            'handlers': ['console', 'console_for_mail_admins'],
            'level': 'INFO',
        },
        'django.server': {
            'handlers': ['django.server'],
            'level': 'INFO',
            'propagate': False,
        },

        'api': {
            'level': LOGLEVEL,
            'handlers': ['console'],
            'propagate': False,
        },
        
        '__main__': {
            'level': LOGLEVEL,
            'handlers': ['console'],
            'propagate': False,
        },
    },
})