python3エンジニア認定実践試験対策③

はじめに

• Python実践レシピに沿って学習します。

以前の記事

• Python3エンジニア認定実践試験対策①
  第4章pythonのクラス、第6章テキストの処理
• Python3エンジニア認定実践試験対策②
  第10章汎用OS・ランタイムサービス、第11章ファイルとディレクトリへのアクセス

今回の範囲

章	タイトル	問題数	問題割合	備考
16	テスト	3	7.5%	16.4 pytest は除く16.5 pydoc は除く
17	デバッグ	2	5.0%	17.3 traceback は除く

16：テスト

doctest

「>>>」や「...」で始まる部分に書かれたコードをテストする
ざっくり言うと「>>>」の後にテストしたいコードを書いて、期待する実行結果をすぐ下の行に記載する
テストの実行方法はdoctestモジュールをインポート後、doctest.testmod()を実行するだけ

知識として覚えておいていいかも

• 後述のunittest実行時にdoctestも実行することができる
• doctestでは集合の並び順が異なる場合、テストに失敗する

sample_doctest.py

"""
与えられた引数に対して、a/bを行う関数です。
>>> divide(5, 2)
2.5
"""

def divide(a, b):
    """
    答えは小数で返ってきます。

    >>> [divide(n, 2) for n in range(5)]
    [0.0, 0.5, 1.0, 1.5, 2.0]
    """
    return a / b

if __name__ == "__main__":
    import doctest
    doctest.testmod()

実行時に-vオプションを付けることで詳細なログを確認できる(-vを付けないで実行した場合、正常に動作が終了しても何も表示されない)

例外も扱うことができる
期待する出力は「Traceback (most recent call last) : 」または「Traceback (innermost kast) : 」から始まる必要がある
トレースバックスタックは省略して書くことが多い

def divide(a, b):
    """
    (省略)

    第二引数が0の場合はエラーが返ってきます。
    >>> divide(5, 0)
    Traceback (most recent call last):
        ...
    ZeroDivisionError: division by zero
    """
    (省略)

別ファイルのテキストファイル内に書かれたコードもテストすることができる
テキストファイル内には同様に「>>>」から始まるテストコードとその下に期待する値を記載する
doctest.testfile()で実行することができる

unittest

ユニットテストの機能

• テストの自動化
• 初期設定と終了処理の共有
• テストの分類
• テスト実行と結果レポートの分離

unittestはunittest.TestCaseのサブクラスとして作成する
testから始まるメソッド名のメソッドをテストの対象とする

example.py

def add(a, b):
    """2つの整数の合計値を取得する"""
    # 意図的なバグを仕込んでいる
    if a == 1 and b == 3:
        return 5
    elif a == 3 and b == 3:
        return 7
    return a + b

test_example.py

import unittest
from example import add


class TestAdd(unittest.TestCase):
    def test_get_the_sum_of_two_integers(self):
        """add()関数のテストコード"""
        acutual = add(1, 2)
        excepted = 3
        self.assertEqual(acutual, excepted)


if __name__ == "__main__":
    unittest.main()

テストの事前準備/事後処理

実行される順番を覚える
setUp()
↓
setUpClass()
↓
tearDownClass()
↓
tearDown()

unittest.mock

モックとはテストが依存しているオブジェクトをインタフェースが同一な疑似オブジェクトに置き換える仕組みのこと
モックオブジェクトを作成する際にMockクラス、MagicMockクラスを利用できる
※MagicMockクラスはMockクラスの持つ機能に加え、pythonが持つすべての特殊メソッドをあらかじめサポートしているため、とくに理由がなければMagicMockクラスを利用するのが良い

sample_processing.py

class ShoppingSiteAPI:
    """架空のショッピングサイトのAPIを呼ぶクラス"""

    def search_items(self, name):
        return "外部APIを呼んだ結果"

    def purchase(self, item_id):
        return "外部APIを呼んだ結果"

def my_processing():
    api = ShoppingSiteAPI()
    return ",".join(api.search_items("商品")) + "が見つかりました"

if __name__ == "__main__":
    print(my_processing())

# pythonの対話モードで実行していると思ってください
>>> from sample_processing import ShoppingSiteAPI
>>> from unittest.mock import MagicMock
>>> api = ShoppingSiteAPI()
>>> api.search_items = MagicMock() # search_items()関数を置き換えるモックオブジェクトを作成
>>> api.search_items.return_value = ["モック商品1", "モック商品2", "モック商品3"] # 返り値を書き換える
>>> api.search_items("商品")
["モック商品1", "モック商品2", "モック商品3"]

patch()

クラスやメソッドをモックオブジェクトして置き換えたい場合はpatch()関数をデコレーターまたはコンテキストマネージャーとして利用します

from sample_processing import my_processing
from unittest.mock import patch
import unittest


class ExampleTest(unittest.TestCase)
    @patch("sample_processing.ShoppingSiteAPI")
    def test_my_processing(self, APIMock):
        api = APIMock()
        api.search_items.return_value = ["モック商品1", "モック商品2", "モック商品3"]

        self.assertEqual(my_processing(), "モック商品1, モック商品2, モック商品3が見つかりました")

if __name__ == "__main__":
    unittest.main()

10：デバッグ

pdb, breakpoint

• pdb: 対話的なデバッガー
• breakpoint: 組み込み関数

sample_pdb.py

import sys
import pdb

def get_system_implementation():
    result = sys.implementation
    pdb.set_trace() # ここがブレークポイント
    return result

def main():
    get_system_implementation()

if __name__ == "__main__":
    main()

sample_pdb.pyに記載したブレークポイントまで処理が流れ、その後デバッグモードに移行する

$ python sample_pdb.py
> d:\icf_autocapsule_disabled\ai_team\study\sample_pdb.py(7)get_system_implementation()
-> return result # ブレークポイントの次の行
(Pdb) h # helpコマンド

Documented commands (type help <topic>):
========================================
EOF    c          d        h         list      q        rv       undisplay
a      cl         debug    help      ll        quit     s        unt
alias  clear      disable  ignore    longlist  r        source   until
args   commands   display  interact  n         restart  step     up
b      condition  down     j         next      return   tbreak   w
break  cont       enable   jump      p         retval   u        whatis
bt     continue   exit     l         pp        run      unalias  where

Miscellaneous help topics:
==========================
exec  pdb

(Pdb) l # 現在いる位置の周囲11行を表示
  2     import pdb
  3
  4     def get_system_implementation():
  5         result = sys.implementation
  6         pdb.set_trace() # ここがブレークポイント
  7  ->     return result
  8
  9     def main():
 10         get_system_implementation()
 11
 12     if __name__ == "__main__":
(Pdb) w # スタックトレースをし表示
  d:\icf_autocapsule_disabled\ai_team\study\sample_pdb.py(13)<module>()
-> main()
  d:\icf_autocapsule_disabled\ai_team\study\sample_pdb.py(10)main()
-> get_system_implementation()
> d:\icf_autocapsule_disabled\ai_team\study\sample_pdb.py(7)get_system_implementation()
-> return result
(Pdb) p result # 変数resultの内容を表示
namespace(name='cpython', cache_tag='cpython-312', version=sys.version_info(major=3, minor=12, micro=4, releaselevel='final', serial=0), hexversion=51119344)
(Pdb) pp result # 変数resultの内容をpprintモジュールを使って整形して表示
namespace(name='cpython',
          cache_tag='cpython-312',
          version=sys.version_info(major=3, minor=12, micro=4, releaselevel='final', serial=0),
          hexversion=51119344)
(Pdb) n # 次の行を処理
--Return--
> d:\icf_autocapsule_disabled\ai_team\study\sample_pdb.py(7)get_system_implementation()->namespace(nam...sion=51119344)
-> return result
(Pdb) c # 次のブレークポイントまで処理を続ける。ブレークポイントがなければ最後まで実行して終了する

breakpoint()を使う場合はこちら

sample_pdb.py

import sys

def get_system_implementation():
    result = sys.implementation
    breakpoint() # ここがブレークポイント
    return result

def main():
    get_system_implementation()

if __name__ == "__main__":
    main()

異常終了時に自動的にデバッグモードに移行するためには実行時に以下のようにする
python -m pdb sample_pdb.py

Pythonの対話モードからデバッグを置こう場合
pdb.run()にデバッグ対象を渡す

対話モードでエラーが発生した場合にデバッグモードへ移行したい場合
エラー後にpdb.pm()で移行できる

timeit

コードの実行時間を計測するモジュール
実行するPythonコードそのものを文字列として渡す必要がある

コマンドラインインターフェースで実行する方法
以下の処理の概要です。

• 計測するコードの内容は"test"という文字列が "This is a test." という文字列の中に含まれているかどうかをチェックする
• 1000万回テスト内容を繰り返す(回数の指定が無い場合は実行時間の合計が少なくとも0.2秒になるように自動で実行される)
• 1000万回繰り返したことを1セットとし、これを5セット繰り返す(デフォルトが5)
• 5セットの中で最も計測時間が短かったものを返す

$ python -m timeit -s '"test" in "This is a test."'
10000000 loops, best of 5: 30.4 nsec per loop

Pythonインターフェースで計測する方法

• timeit: 指定したコードをn回(デフォルトは100万回)繰り返す。globalsがデフォルトのNoneの場合、名前空間timeitが指定される
• repeat: 指定したコードをn回(デフォルトは100万回)繰り返すことをm回繰り返す(デフォルトは5回)

>>> import timeit
>>> timeit.timeit('"test" in "This is a test."')
0.033071500016376376
>>> timeit.repeat('"test" in "This is a test."')
[0.0352827999740839, 0.03224239987321198, 0.03130289982073009, 0.03131540003232658, 0.031143000116571784]

知識として覚えておいていいかも

• timeit()の中に直接定義していない自作関数などを実行する場合はglobals引数を設定しないとエラーする

>>> def foo():
...     pass
...
>>> import timeit
>>> timeit.timeit('foo()')
Tracebask (most recent call last):
    （省略）
NameError: name 'foo' is not defined

globalsオプション指定時

>>> timeit.timeit('foo()', globals=globals())
0.06397334400003274

logging

ログレベルは高い順にCRITICAL、ERROR、WARNING、INFO、DEBUG、NOTSET
指定したログレベル以上のログレベルのメッセージが表示される(デフォルトはWARNING)
例えばログレベルをWARNINGに設定すると、CRITICAL、ERROR、WARNINGのログが表示される

>>> import logging
>>> logging.debug("debug message")
>>> logging.warning("warning message")
WARNING:root:warning message

logging.basicConfig()を使うことでログレベルや出力フォーマット、出力先などロギングの挙動を変更することが出来る

>>> logformat = "%(asctime)s %(levelname)s %(message)s"
>>> logging.basicConfig(filename="/tmp/test.log", # 出力先の変更
...                     level=logging.DEBUG, # ログレベルの変更
...                     format=logformat) # 出力フォーマットの変更
...
>>> logging.debug("debug message")
>>> logging.info("info message")
>>> logging.warning("warning message")

今回の例だと/tmp/test.logに以下の内容のログが出力されている

2025-04-03 14:04:24,547 DEBUG debug message
2025-04-03 14:04:31,539 INFO info message
2025-04-03 14:04:36,792 WARNING warning message

モジュール方式でロギングを設定する

以下にある部品を組み合わせて柔軟にロギングを構成する
例

• 1つのロガーに複数のハンドラーを設定する
  • コンソールとファイル両方への主力
• 2つのロガーにそれぞれ別のハンドラーを設定する
  • ロガーAはファイル出力、ロガーBはメールを送信

名前	内容
ロガー	ログ出力のインターフェースを提供する
ハンドラー	ログの送信先を決定する
フィルター	ログのフィルタリング機能を提供する
フォーマッター	ログの出力フォーマットを提供する

>>> import logging
>>> logger = logging.getLogger("hoge.fuga.piyo") # hoge,figa.piyoという名前を設定
>>> logger.setLevel(logging.INFO) # INFOレベル以上のログを設定する
>>> handler = logging.FileHandler("/tmp/test.log") # ファイルを出力先とするハンドラーを設定
>>> handler.setlevel(logging.INFO) # INFOレベル以上のログを設定する
>>> logging_filter = logging.Filter("hoge.fuga") # ロガー名がhoge.fugaにマッチする場合のみ出力するフィルターを作成
>>> formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
>>> handler.setFormatter(formatter) # ハンドラーにフォーマッターを設定
>>> handler.addFilter(logging_filter) # ハンドラーにフィルターを設定
>>> logger.addHandler(handler) # ロガーにハンドラーを設定
>>> logger.addFilter(logging_filter) # ロガーにフィルターを設定
>>> logger.debug("debug message")
>>> logger.info("info message")

辞書やファイルからロギングを設定することもできる

• dictConfig(): 辞書オブジェクトからロギングを設定する
• fileConfig(): ファイルに記述された内容に基づいてロギングを設定する(フィルター設定は不可)
  以下は先ほどモジュール方式でロギングを設定したものを辞書形式に書き換えた例

import logging
from logging.config import dictConfig

config = {
    "version": 1, # dictConfigフォーマットのバージョン。1のみサポートされる
    "disable_existing_loggers": False, # Falseの場合は既存のロギング設定を無効化しない
    "formatters": { # フォーマッター設定を構成する辞書
        "example": { # フォーマッター名
            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
        },
    },
    "filters": { # フィルター設定を構成する辞書
        "hoge-filter": { # フィルター名
            "name": "hoge.fuga", # フィルター対象のロガー名
        },
    },
    "handlers": { # ハンドラー設定を構成する辞書
        "file": { # ハンドラー名
            "level": "INFO", # ハンドラーのログレベルを指定する
            "class": "logging.FileHandler", # ハンドラーのクラス
            "filename": "/tmp/test.log", # 出力先のファイルパス
            "formatter": "example", # ハンドラーにセットするフォーマッター名
            "filters": ["hoge-filter"], # ハンドラーにセットするフィルター名のリスト
        },
    },
    "loggers": { # ロガー設定を構成する辞書
        "hoge": { # ロガー名
            "handlers": ["file"], # ロガーが利用するハンドラー名のリスト
            "level": "INFO", # ロガーのログレベル
            "propagate": True, # Trueの場合はこのロガーに設定を伝播する
        },
    },
}
dictConfig(config)
logger = logging.getLogger("hoge.fuga.piyo")
logger.debug("debug message")
logger.info("info message")

ロガーの階層構造

logging.getLogger()に渡したロガー名に「.(ドット)」が含まれる場合、ロガーを階層構造として認識する

hoge.fuga.piyoの親ロガーはhoge.fugaで、さらにその親はhogeとなる
全てのロガーの階層構造には共通の親ロガーが存在し、これはルートロガーと呼ばれる
親ロガーが設定したハンドラーは子ロガーは共通して使うことが出来る

知識として覚えておいていいかも

• logging.getLogger(name)のように__name__をロガー名としたロガーをモジュールレベルロガーと呼ぶ