loggingとloggerは区別する

親子を区別する

親：
- loggingおよびそのログ設定 logging.basicConfig(level=~)
子：
- logger=logging.getLogger(__name__) および logger.setLevel(~) 等
- importされたモジュールのロガー

basicConfig を記載することで、当ファイルでの logger(__name__) や import された関数も含めた全体のログ管理を行える

同一ファイルで logging と logger の双方でログを出すとわかりにくいが、 %name で見分けられる
- 例）メインファイルで、同時に標準出力すると重複したログが出てしまう
- logging.debug の場合、%nameは「root」になる
- logger.debug の場合、%nameは「__main__」になる
- （importした場合は、モジュール名）

１ファイルのログ取りであれば、logging か logger の１つだけを利用したほうがわかりやすい
また「標準出力」「ファイル出力」のいずれか１つだけであれば ①logging だけでよい（②でもよいが）
２つ同時利用なら、①は使わず、②③のロガーを利用したほうがよい
下表を参照

両者の使い分け

	①logging.basicConfig() 親	②logging.StreamHandler() 子（ロガー利用時）	③logging.FileHandler 子（ロガー利用時）
A. コンソール出力（標準出力）	〇	〇	–
B. ファイル出力	〇	–	〇
C. 両方（A＋B）	× 同時利用はできない	〇 with FileHandler()	〇 with StreamHandler()
備考		②③両方使用の際は ①は使わないのがベター	同左

記法

コンソール（標準）出力

1ファイルだけのログ取りを想定、logging(親) を利用
もっともシンプルな記法

import logging

formatter = '[%(asctime)s] %(levelname)s: %(message)s'
logging.basicConfig(level=logging.INFO, format=formatter)

logging.debug('This is "debug" msg.')
logging.info('This is "info" msg.')

補足：basicConfig のオプション

# ロガーの名前を付けたい場合
formatter = '[%(asctime)s] %(name)s %(levelname)s: %(message)s'
# (asctime)の日付形式でミリ秒を消したい場合
logging.basicConfig(level=logging.INFO, format=formatter,
                    datefmt='%F %H:%M:%S')

ファイルにログ出力

１ファイルだけのログ取りを想定、logging(親) を利用
logging.basicConfig に filename= を追加する
この場合、コンソールには出力されない

logging.basicConfig(level=logging.INFO, format=formatter,
                    filename='./log_test.log) # 出力先のファイル名

コンソールとファイル両方に出力したい★

1ファイルだけのログ取りを想定
logging (親) は両方できないため、logger(子) を別に作ってそっちに動いてもらう
その logger に対し、標準出力の機能 StreamHandler()、ファイル出力の機能 FIleHandler() をそれぞれ追加 addHandler すればよい
注意点は、import したモジュールのログを取るなどの目的がなければ、このケースでは logging (親) の logging.basicConfig(～) は記載しない書き方がベター。
もし、途中片方だけにしたければ、削るなりすればよい

import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
formatter = '[%(asctime)s] %(levelname)s: %(message)s'

# ハンドラーを生成する（コンソール用）ß
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.WARNING)
stream_handler.setFormatter(logging.Formatter(formatter))
logger.addHandler(stream_handler)

# ハンドラーを生成する（ファイル出力用）
file_handler = logging.FileHandler("log_test.log")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(logging.Formatter(formatter))
logger.addHandler(file_handler)

# ログ出力
logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')
logger.error('This is error message')
logger.critical('This is critical message')

StreamHandler() 標準出力（コンソール）は「Warning」以上が出力

▼ちなみに。混在させてもよいが、これだと後から標準出力だけを止めることができない。

import logging

formatter = '[%(asctime)s] %(levelname)s: %(message)s'
logging.basicConfig(level=logging.DEBUG, format=formatter)

logger = logging.getLogger(__name__)

# 標準出力は不要（親のlogging.basicConfigがあるため）

# ハンドラーを生成する（ファイル出力用）
file_handler = logging.FileHandler("log_test.log")
file_handler.setLevel(logging.INFO) # loggingと同じであれば不要
file_handler.setFormatter(logging.Formatter(formatter)) # 同上
logger.addHandler(file_handler)

logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')
logger.error('This is error message')
logger.critical('This is critical message')

▼ 悪い例。logging と logger のそれぞれからログを取っている。重複したログが出てしまう。用途を理解していない当初はこのように書いていた。

# 避けたほうがよい例
logging.basicConfig(〜）
logging.debug('debugA')

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.debug('debugB')

その他

ロギング関数

ロギング関数には、そのイベントの「レベル」や「重大度」で分けられる

レベル（重大度は小→大）	いつ使うか
DEBUG	開発中のみに利用。詳細な情報を確認したいとき
INFO	想定された通りのことが起こったことの確認をしたいとき
WARNING	想定外のことが起こった、または問題が近く起こりそうなとき（プログラムは動いている）デフォルトではWARNINGレベル以上がログに残る
ERROR	より重大な問題により、プログラムがある機能を実行できないとき
CRITICAL	プログラム自体が実行を続けられない重大なエラーが起こったとき

ログ出力の結果

（ログレベル）：（ロガーの名前）：（メッセージ）
- 例）DEBUG:root:message
- ロガーとはログを出力するオブジェクトのこと
デフォルトのなにも設定しない状態では WARNING レベル以上のログが表示される
debug や critical レベルを表示させたい場合は、
logging.basicConfig(level=logging.〜〜)の設定が必要

import logging

logging.basicConfig(level=logging.DEBUG) # DEBUG以上をログ出力

logging.debug('debug')
logging.info('info')
logging.warning('warning')
logging.error('error')
logging.critical('critical')

>>DEBUG:root:debug 
>>INFO:root:info
>>WARNING:root:warning
>>ERROR:root:error
>>CRITICAL:root:critical

ログの整形

import logging

logging.basciConfig(filename='test.log', level=logging.INFO)

logging.info('info {}'.format('test'))

# test.log内
INFO:root:info test

フォーマットを設定

（ログレベル）：（ロガーの名前）：（メッセージ）、のフォーマットは変更可能

import logging

formatter = '%(levelname)s:%(messages)'
logging.basicConfig(level=logging.INFO, format=formatter)

logging.info('info %s %s', 'test1', 'test2') # ロガーの名前（root）を消した
>>INFO:info test1 test2

LogRecord属性

https://docs.python.org/ja/3/library/logging.html#logrecord-attributes

{}フォーマット（str.format()）の場合
- {attrname}形式
$フォーマット（string.Template）の場合
- ${attrname}形式

import logging

formatter = '%(levelname)s:%(message)s'
logging.basicConfig(level=logging.INFO, format=formatter)

logging.info('info %s %s', 'test', 'test2')

>>INFO:info test test2

import logging

formatter = '%(asctime)s:%(message)s'
logging.basiConfig(level=logging.INFO, format=formatter)

logging.info('info %s %s', 'test', 'test2)
>>2022-11-12 10:13,232:info test test2

logging.warning('is when this event was logged.')
>>2022-11-12 10:14,232 is when this event was logged.

import logging
logging.basicConfig(format='%(asctime)s %(message)s', datefmt='%Y/%m/%d %I:%M:%S %p')
logging.warngin('is when this event was logged.')

>>2022/11/12 10:14,232 is when this event was logged.

ロガー

getLoggerメソッドで、ロガー（オブジェクト）をつくる
作ったロガー毎に、ログレベルを個別に設定することができる
getLoggerの引数には「 __name__ 」を指定する（固定名でもOK）
これが「ロガーの名前」となり、ログに出力されるようになる
- この場合、出力されるロガーの名前は「__main__」になる
このロガーに setLevel を使って個別にログレベルを設定する。
basicConifig（全体向け）のログレベルをINFOにしても、個別のロガーはDEBUGレベルにしたりすることができる

import logging

# basicConfigの設定がないと、下でsetLevelしても何も表示されない ←ちがう。ログレベルのデフォルトがWARNING以上だから、DEBUGがでないだけ
logging.basicConfig(level=logging.INFO)

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logger.debug('debug')

# ログ出力すると、ロガーの名前として変数__name__の中身である
# __main__が出力される。
>>DUBUG:__main__:debug

# 試しにgetLoggerの引数を変えると、ログの表示も変わる

logger = logging.getLogger('ABC')
logger.setLevel(logging.DEBUG)
logger.debug('debug')

>>DEBUG:ABC:debug

ロガーを作成するときのコツ

getLoggerの引数には、__name__を渡すのがよいやり方とされている
試しに、新たにlogtest.pyというファイルを作成する。logtest.pyの中でロガーを作成し、do_somethingというINFOでログを出力だけの関数を定義しておく

import logging

logger = logging.getLogger(__name__)

def do_something():
  logger.info('from logtest')

このlogtest.pyをlesson.pyでインポートして、logtest.py内のdo_something関数（中にlogger.infoが記述されている）を実行してみる
logging.infoでログを出力すると、ロガーの名前はrootになる
対してlogtest.pyのロガーの出力を見ると、モジュール名であるlogtestが表示されていることがわかる

import logging

import logtest

logging.basicConfig(level=logging.INFO)
logging.info('info')
logtest.do_something()

>>INFO:root:info
>>INFO:logtest:from logtest

ここで、logtest.pyの処理にDEBUGのログ出力を加えてから、もう一度lesson.pyを実行してみる
すると、DEBUGのメッセージは表示されない（行7の処理）
これはログレベルの設定がINFO（＞DEBUG）に設定されているため

import logging

logger = logging.getLogger(__name__)

def do_something():
  logger.info('from logtest')
  logger.debug('from logtest debug') # DEBUGの処理を追加

# lesson.pyからlogtest.pyをimportし、実行しても、上記のDEBUGのMSGは表示されない（INFO以上に設定されているため）
>>INFO:roort:info
>>INFO:logtest:from logtest

lesson.pyにも以下のようなロガーを作成してロギングしてみる
__main__と出力されているため、どの処理のログなのかがわかりやすくなる
また、ログレベルの設定がロガー毎に異なっているのがわかる

import logging

import logtest

logging.basicConfig(level=logging.INFO)

logger = logging.getLogger(__name__)
logger.info('from main')

logtest.do_something()

>>INFO:__main__:from main
>>INFO:logtest:from logtest

処理ごとにロガーを作成する

アプリの開発を行う際は、最初にメインとして実行する処理でlogging.basicConfigによってログレベルを設定し、その後はロガーを作成してログ出力をしていくのが基本となる
処理によってはファイルにログ出力したり、パスワードのような情報はロギングしないようにしたりと、個別のログ設定が必要になってくる場合がある。そのため、Webサーバー関連とそれ以外のように処理ごとにロガーを作成し、それぞれでカスタマイズしていくのが良いやり方といわれている

ハンドラー

ログをファイルに出力するといった出力先の設定を行うには、ハンドラーを作成してロガーに渡す必要がある
以下の例では、logtest.pyの処理において、まずFileHandlerでログ出力先をlogtest.logとするハンドラーを作成している
その後、addHandler メソッドでハンドラーをロガーに渡している
この状態で、do_something()関数の中で、ロガーを用いた場合とそうでない場合とでログ出力を行ってみると

# ハンドラーでログの出力先をファイルに設定
import logging

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

h = logging.FileHandler('logtest.log')
logger.addHandler(h)

def do_something():
  logging.info('from logtest info') # ←これだけはFileHandlerで出力先を指定されてない
  logger.info('from logtest')
  logger.debug('from logtest debug)

# 上記のlogtest.pyの処理を、lesson.pyから呼び出して実行すると
import logging

import logtest

logging.basicConfig(level=logging.INFO)　
logger = logging.getLogger(__name__)
logger.info('from main')
logtest.do_something()

コンソールには、すべてのログ出力が表示されている

# コンソール画面
INFO:__main__:from main
INFO:root:from logtest info
INFO:logtest:from logtest
DEBUG:logtest:from logtest debug

対して、logtest.logには、logtest.pyでハンドラーを設定したロガーによる出力だけがファイルに書き込まれている
logtest.pyで出力先を指定されなかった「logging.info(‘from logtest info’)」は表示されてない

# logtest.logへ書き込まれた内容
from logtest
from logtest debug

さまざまなハンドラー

ハンドラーの種類（Python公式）
例
- ファイルに出力する（FileHandler）
- 画面に出力する（StreamHandler）＝標準出力
- ネットワーク越しにログを書き込む（SocketHandler）
- Linuxなどで使われることの多いSyslogを扱う（SyslogHandler）
- ログをメールで送信できる（SMTPHandler）、など

フィルタを使ってログ出力の条件を設定しよう

パスワードなどの機密情報はログ出力すべきではない
フィルタを使うと、たとえばログに「password」の文字列が含まれる場合など、特定の条件でログを出力しないようにする設定が可能
フィルタを使うには、logging.Filterを継承したクラスを作成し、filterメソッドをオーバーライドしていく
filterメソッド内の処理では、ログのメッセージにpasswordの文字列が含まれているかをチェックし、含む（True）、含まない（False）を返すようにする
ログのメッセージはrecord.getMessageで取得できる
このフィルタをロガーにaddFilterメソッドで設定すると、passwordという文字列が含まれるログは出力されなくなる

import logging

logging.basicConfig(level=logging.INFO)

class NoPassFilter(logging.Filter):
  def filter(self, record):
    log_message = record.getMessage()
    return 'password' not in log_message

logger = logging.getLogger(__name__)
logger.addFilter(NoPassFilter())
logger.info('from main')
logger.info('from main password = "test")

INFO:__main__:from main

ログの設定ファイルを作成しよう

ロガーの設定をファイルとして作成しておき、それを読み込んで使うこともできる
ログの設定ファイルを読み込むときは、logging.configのfileConfig関数で設定ファイルを指定する

import logging.config

logging.config.fileConfig('logging.ini')　# 下のような設定ファイルを読み込む

一例だが、ログの設定ファイルは以下のような形になっている

[loggers] # 使用するロガーの名前（固定）を記載。ロガーの名前、rootはトップレベルのロガー（__name__）。getLoggerでロガーの名前を固定で指定する
keys=root,simpleExample

[handlers]
keys=streamHandler

[formatters]
keys=formatter

[logger_root] # rootのロガー設定
leve=WARNING
handlers=streamHandler

[logger_simpleExample] # simpleExampleの設定
level=DEBUG
handlers=streamHandler
qualname=simpleExample
propagate=0

[handler_streamHandler]
class=StreamHandler
level=DEBUG
formatter=formatter
args=(sys.stderr,)

[formatter_formatter]
format=%(asctime)s %(name)-12s %(levelname)-8s %(message)s

import logging.config

logging.config.fileConfig('logging.ini')
logger = logging.getLogger(__name__)

# ログ出力
logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')
logger.error('This is error message')
logger.critical('This is critical message')

ロガー名をsimpleExampleにすると、logging.iniで記述されたsimpleExampleのログレベル設定（Debug以上）が反映される

import logging.config

logging.config.fileConfig('logging.ini')
logger = logging.getLogger('simpleExample')

# ログ出力
logger.debug('This is debug message')
logger.info('This is info message')
logger.warning('This is warning message')
logger.error('This is error message')
logger.critical('This is critical message')

月	火	水	木	金	土	日
			1	2	3	4
5	6	7	8	9	10	11
12	13	14	15	16	17	18
19	20	21	22	23	24	25
26	27	28	29	30	31

Logging

loggingとloggerは区別する

親子を区別する

両者の使い分け

記法

コンソール（標準）出力

ファイルにログ出力

コンソールとファイル両方に出力したい★

その他

ロギング関数

ログ出力の結果

ログの整形

フォーマットを設定

LogRecord属性

ロガー

ロガーを作成するときのコツ

処理ごとにロガーを作成する

ハンドラー

さまざまなハンドラー

フィルタを使ってログ出力の条件を設定しよう

ログの設定ファイルを作成しよう

ロギングの実践的な書き方を学ぼう