僕がPythonのデバッグをするときによくやること

こんにちは。matobaです。この記事は、BeProud Advant Calendarの4日目の記事です。僕にとっては初めてのAdvant Calendarの記事です。

昨日更新できれば良かったのですが、BeProud Advant Calendar に登録してたことを忘れていました。と言うわけで書きます。

今日は、僕がPythonのデバッグをするときによくやることを紹介します。 1年前の僕だとスムーズにできなかったこともたくさんあるので、参考になれば、と思います。あと、僕も勉強中の人なので、これやるともっとスムーズだよ。と言うのがあれば教えてもらえるとありがたいです。

サンプルコード
まずエラーが出るユニットテストを書く
エラーメッセージでググる
リポジトリのIssueを見る
venv環境の動いてるコードを見る
pdbでブレークポイントをうって挙動を確かめる
その他1：gitリポジトリをcloneして見る
その他2：git blame, git showを使う
終わり
2023.07.05追記

サンプルコード

parse_ignoretz と言う関数をデバッグします。この関数は、与えられた文字列をparseしてdatetime.datetimeのオブジェクトにして返します。

sample.py

import dateutil.parser


def parse_ignoretz(date_stirng):
    return dateutil.parser.parse(date_stirng, ignoretz=True)

test_sample.py

import datetime
import unittest

import sample


class MySample(unittest.TestCase):
    def test_parse(self):
        date_string = "1986-07-05T08:15:30Z"
        result = sample.parse_ignoretz(date_string)
        self.assertIsInstance(result, datetime.datetime)

とりあえず、pytestを使うとちょっと違う話になると思いますが、今回は置いといてください。

これを以下の環境でユニットテストを実行すると通ります。

$ python3.6 -m venv venv
$ . venv/bin/activate
(venv) $ pyhton -V
Python 3.6.5
(venv) $ pip install python-dateutil==2.7.5
(venv) $ python -m unittest
.
----------------------------------------------------------------------
Ran 1 test in 0.000s

OK

しかし、この関数は、引数に「"1986-07-05T08:15:30z"」を渡すとエラーが出ます。そのエラーを解消したい。と言う状況を考えます。

まずエラーが出るユニットテストを書く

エラーが出てそれを解消するとき、まずはエラーが出るユニットテストを書くのがスタート地点です。

でないと何を直してるのかわからなくなります。以下のようなことを繰り返して疲弊します。

あるエラーを直した後に別の修正をして同じエラーに苦しむ。
別の修正をしたときにデグレートしたことに気づかず、後になって気づく。
あっちを直せばこっちが壊れ、こっちを直せばあっちが壊れる。

まず、何をどう言う状態にしたいのかを明らかにして、それを解消する、と言うふうに一歩一歩前に進むといいでしょう。そのためにユニットテストを書きます。

1年前の自分に伝えたいです。

追加後のテストコード。

import datetime
import unittest

import sample


class MySample(unittest.TestCase):
    def test_parse(self):
        date_string = "1986-07-05T08:15:30Z"
        result = sample.parse_ignoretz(date_string)
        self.assertIsInstance(result, datetime.datetime)

    def test_parse_error(self):
        date_string = "1986-07-05T08:15:30z"
        result = sample.parse_ignoretz(date_string)
        self.assertIsInstance(result, datetime.datetime)

ユニットテストの結果

$ python -m unittest
.E
======================================================================
ERROR: test_parse_error (test_sample.MySample)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/home/ubuntu/debug_sample/test_sample.py", line 15, in test_parse_error
    result = sample.parse_ignoretz(date_string)
  File "/home/ubuntu/debug_sample/sample.py", line 5, in parse_ignoretz
    return dateutil.parser.parse(date_stirng, ignoretz=True)
  File "/home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py", line 1356, in parse
    return DEFAULTPARSER.parse(timestr, **kwargs)
  File "/home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py", line 648, in parse
    raise ValueError("Unknown string format:", timestr)
ValueError: ('Unknown string format:', '1986-07-05T08:15:30z')

----------------------------------------------------------------------
Ran 2 tests in 0.002s

FAILED (errors=1)

デバッグできた。とは、このテストが通るようになったことを意味することにしましょう。

エラーメッセージでググる

当たり前すぎるので、詳しくは書きませんが、とりあえず最初は、エラーメッセージでググりましょう。

似たエラーがあれば、そこで問題は解消します。

今回は、ググってすぐにわからないパターンを考えます。

リポジトリのIssueを見る

python-dateutil は、オープンソースのライブラリです。

Pythonのライブラリの多くはオープンソースです。そして、多くの場合、githubにリポジトリがあって、issueが立てられます。複数の人が遭遇した問題は、issueに登録されている可能性が高いです。

と言うわけでIssueを検索しましょう。ちなみにリポジトリのIssueは、Google検索にあまり引っかかりません。だから自分でライブラリのリポジトリを探して、リポジトリの検索窓から検索する必要があります。

リポジトリは、PyPIから探すといいです。

pypi.org

いつもpipでインストールしているライブラリは、PyPIで管理されています。

PyPIには、ライブラリごとにページがあります。ライブラリのページには、そのライブラリのリポジトリが登録されていることが多いです。

python-dateutils の場合は、ここがPyPIのページになります。

pypi.org

そこからリポジトリを見つけます。だいたいgithubにあるので、githubの検索窓から探しても良いと思います。

github.com

次に、Issueを探します。検索キーワードは、エラーメッセージが良いでしょう。今回の場合は、 Unknown string format です。

今回の場合は、上記のキーワードで探すと次のIssueが見つかります。

github.com

まあ、今回は、Issueが見つからなかった、と言うことで進めます。

venv環境の動いてるコードを見る

未知のエラーに遭遇した場合、エラーがどこで発生しているかを確認しましょう。

ユニットテストで出ているスタックトレースを見ます。

今回の場合、以下を見ます。

  File "/home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py", line 648, in parse

要は、 /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py と言うファイルの648行目でエラーが出ています。

/home/ubuntu/debug_sample/venv/ と言うのは今回作成したvenvのパスです。

作成したvenvでpip installをすると、その中の lib/python3.6/site-packages/ の中にライブラリのコードがインストールされます。実行時はそこを参照しているわけです。

だから普通に以下のようにすると、そのファイルを開くことができます。

$ vim /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py

ちなみに、 vim の場合 +648 とつけると、 648 行目にカーソルを移動して開くことができて便利です。

$ vim /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py +648

pdbでブレークポイントをうって挙動を確かめる

ライブラリのソースコードを開いて、該当箇所を見たらだいたい何が起きたのかわかる時もあります。

わからない時は、pdbを使って挙動を確かめます。pdbはPythonデバッガーです。

以下のように追加します。

    def test_parse_error(self):
        import pdb;pdb.set_trace() # 追加した。ここがブレークポイント
        date_string = "1986-07-05T08:15:30z"
        result = sample.parse_ignoretz(date_string)
        self.assertIsInstance(result, datetime.datetime)

これでテスト実行するとデバッグモードに入れます。

$ python -m unittest
.> /home/ubuntu/debug_sample/test_sample.py(15)test_parse_error()
-> date_string = "1986-07-05T08:15:30z"
(Pdb)

今回エラーが起きたのは、 /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py の648行目なので、以下のように指定します。

(Pdb) b /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py:648
Breakpoint 1 at /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py:648

すると、エラーが発生する行を実行する直前で止まるようになります。pdb では、c を実行すると次のブレークポイントまで進みます。

(Pdb) c
> /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/dateutil/parser/_parser.py(648)parse()
-> raise ValueError("Unknown string format:", timestr)

l を押すと、該当箇所のコードが見れます。

(Pdb) l
643                                                           second=0, microsecond=0)
644
645             res, skipped_tokens = self._parse(timestr, **kwargs)
646
647             if res is None:
648 B->              raise ValueError("Unknown string format:", timestr)
649
650             if len(res) == 0:
651                 raise ValueError("String does not contain a date:", timestr)
652
653             ret = self._build_naive(res, default)

p で変数の中身を見れます。

(Pdb) p res
None
(Pdb) p timestr
'1986-07-05T08:15:30z'

要は、 self._parse() にtimestrの文字列を渡した時に、resがNoneだったからエラーが出たんだなーといのがわかります。

こんな感じで頑張って掘っていくと、Issueに書いてある問題が見つかると思います。

その他1：gitリポジトリをcloneして見る

もっとライブラリの処理の内容が知りたくなってきたら、リポジトリをcloneします。 venvの中で見てもいいのですが、gitリポジトリがある方が何かと便利なことがあるので、cloneしちゃいます。

$ git clone git@github.com:dateutil/dateutil.git

リポジトリの中に、 /home/ubuntu/debug_sample/venv/lib/python3.6/site-packages/ にインストールされていたコードと同じコードがあるはずなので見ます。

ライブラリをバージョンアップした時は、前のバージョンのコードを見たい時があります。そう言う時は、gitリポジトリを操作して、指定したバージョンに切り替えてコードを見ます。

その他2：git blame, git showを使う

バージョンアップした時は、知らないうちに挙動が変わることがあります。 Release Noteに書いてる時もあれば、書いてないこともあります。そう言う時は、エラーが出ているコードがなぜそう言う形になっているかを確かめるために、git blameを行います。

git blameを使うとそのコードがいつ変更されたのかを知ることができます。

例えば、dateutilのリポジトリで以下のように実行すると、644-650の行がいつ更新されたのかを知ることができます。

$ git blame -L 644,650 dateutil/parser/_parser.py
95f82136 dateutil/parser.py (Paul Ganssle       2015-07-26 11:33:34 -0400 644)                                                       second=0, microsecond=0)
1c491217 dateutil/parser.py (Christopher Corley 2012-12-24 12:57:01 -0600 645)
0cd37844 dateutil/parser.py (Michael Aquilina   2015-06-07 00:40:30 +0100 646)         res, skipped_tokens = self._parse(timestr, **kwargs)
1c491217 dateutil/parser.py (Christopher Corley 2012-12-24 12:57:01 -0600 647)
6b3c20f1 dateutil/parser.py (niemeyer           2003-10-06 05:50:42 +0000 648)         if res is None:
af576ed4 dateutil/parser.py (Peter Bieringer    2016-10-16 20:20:58 +0000 649)             raise ValueError("Unknown string format:", timestr)
b8b87cd0 dateutil/parser.py (Paul G             2015-02-05 11:19:51 -0600 650)

ちなみに、今回エラーが発生した行は 2016-10-16 20:20:58 に修正されています。これで少なくとも1年以内の更新ではないんだな、などのことがわかります。

修正されたコミットの内容を見る時は、以下のように実行します。

$ git show af576ed4
commit af576ed44f6803676dba300be3bdb05e82c4cd8c
Author: Peter Bieringer <pb@bieringer.de>
Date:   Sun Oct 16 20:20:58 2016 +0000

    add rejected timestr in exception message providing more information to caller

diff --git a/dateutil/parser.py b/dateutil/parser.py
index 147b3f2..b4a9fa9 100644
--- a/dateutil/parser.py
+++ b/dateutil/parser.py
@@ -556,10 +556,10 @@ class parser(object):
         res, skipped_tokens = self._parse(timestr, **kwargs)

         if res is None:
-            raise ValueError("Unknown string format")
+            raise ValueError("Unknown string format:", timestr)

         if len(res) == 0:
-            raise ValueError("String does not contain a date.")
+            raise ValueError("String does not contain a date:", timestr)

         repl = {}
         for attr in ("year", "month", "day", "hour",

これは、エラーが出た時のメッセージが改善されたコミットですかね。こんな感じで、該当の行がどう言う理由でいつ変更されたのかを知ることができます。

コミットにはIssue番号が付いている時もあるので、ついている時はそこからさらに詳細な情報を追うことができます。

終わり

今回は、僕がPythonのデバッグをしている時によくやることを紹介しました。

僕は、基本的にコマンドラインだけで開発してるのでこんな感じになってますが、GUIアプリを使うともっとスムーズにできるのかもしれません。*1

他にもこれ使う方が便利だよと言うのがあれば、また教えてもらえればと思います。

ではでは

2023.07.05追記

こちらの記事を紹介する機会があったので見返したところ、最新情報があったので、追記しておきます。

記事の中ではブレークポイントを打つ際に import pdb;pdb.set_trace() を実行していますが、最新のPythonだと breakpoint() で同じ効果が得られます。

Python3.7 以降で導入されました。新しいPythonのプロジェクトの場合はこっちを使いましょう。

組み込み関数 — Python 3.11.4 ドキュメント

*1:ちなみに僕がコマンドラインだけで開発してる理由は、GUIアプリはよくバグる印象があるし、バグった時に無力でイライラしてしまって精神衛生上よくないからです。

matobaの備忘録

和歌山と東京を往復しつつ活動するエンジニアの記録