デバッグの手法について知ろう

前回から、書かれたプログラムが期待どおりに動いているかどうかを確認する手法について扱っています。今回はデバックについて解説していきます。

Printデバッグ

まず最初は一番シンプルなprintデバッグです。printデバッグという名前から想像できるかもしれませんが、その使い方はいたって単純です。簡単に言ってしまうと、プログラムの途中にプログラムとは直接関係のないprint文を「今どこを実行しているかを連番などで表示」したり、「怪しい変数の中身を表示」したりするためにはさみます。

たとえば以下のコードがあるとしましょう。

print(1)
a = 1
print(2)
b = 2
print(3)
c = 3
print(4)
d = a + b
print(5)
e = 5 / (c - d)
print(6)
f = e**2

このコードではプログラムの1行ごとにどこまで進んでいるかをprint文で表示させています。きちんと読めばわかりますがe = 5 / (c - d)のところにバグがあるので、実行させるとここで止まります。

python test.py
1
2
3
4
5
Traceback (most recent call last):
  File "test.py", line 10, in <module>
    e = 5 / (c - d)
ZeroDivisionError: integer division or modulo by zero

print(5)相当の表示はあるものの、print(6)の表示はありません。そのため、5と6の間に問題があることがわかります。なお、今回はスタックトレースにもろに原因が書かれていますね。問題が発生したコードがどのように呼びだされたかというピンポイントの場所は特定できます。もう少し複雑なプログラムになったときに「どういう流れでそれに至ったか」を調べるときに使ったりします。

問題箇所を特定できた次のステップとして、今度は変数をprintしてみてどう動いているのかを特定する作業に入ります。今回は単純なプログラムなのでそれは割愛します。

printデバッグはやや場当たり的な手法となりますのでその使用に賛否両論がありますが、「一番簡単」「環境に依存しない」「Pythonはコンパイルに時間がかからず、小さいスクリプトだと害はほとんどない」という理由で、巨大なコードを調べる場合以外は問題ないと私は考えています。

pdbを使ったインタラクティブなデバッグ

デバッガはデバッグ作業を手助けしてくれるツールです。先ほどのようにprintデバッグするのでもいいですが、より詳細な動きを調べたかったり、コードを変更することができない場合などといった状況でprintデバッグより便利に使えます。

pdbは「シェルでインタラクティブにデバッグする方法」と「デバッグ用のコードを直接書く方法」の2つがあります。まず前者を試してみます。以下にバグのあるコードを提示します。

def divide(a, b):
    return a/b

def test():
    print(divide(5,3))
    print(divide(2,1))
    print(divide(1,8))
    print(divide(4,0)) # BUG
    print(divide(3,2))

test()

インタラクティブにデバッグする方法ではデバッガPDBに対してコマンドで指令を与えながらプログラムを解析していきます。コマンドにもいろいろあるのですが、いきなり多くを扱うと混乱するので、まずはプログラムを進めるstep、nextそして現在位置の表示をするlistです。

• step: 実行を1行進める
• next: 実行を1行進めるが、関数呼び出しはreturnされるまで一気に進める
• list: 現在実行しているコードの位置を表示

とりあえず、シェルモードで起動してみます。PDBのシェルモードでの起動は以下のように"-m pdb"のオプション付きで行います。

# python -m pdb test2.py
> /Users/yuichi/Scripts/test2.py(1)<module>()
-> def divide(a, b):
(Pdb)

まずはPythonがプログラムを読んでいく処理です。1行目の「divide関数の定義」の位置で止まっています。

試しにstepとlistを使ってみます。どんどんコードを読んでいくことがわかるはずです。なお、コマンドを全文字打ち込んでもかまわないのですが、s、lというように頭文字だけコマンドを打てば動きます。

(Pdb) l
  1  -> def divide(a, b):
  2         return a/b
  3
  4     def test():
  5         print(divide(5,3))
  6         print(divide(2,1))
  7         print(divide(1,8))
  8         print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11     test()
(Pdb) s
> /Users/yuichi/Scripts/test2.py(4)<module>()
-> def test():
(Pdb) l
  1     def divide(a, b):
  2         return a/b
  3
  4  -> def test():
  5         print(divide(5,3))
  6         print(divide(2,1))
  7         print(divide(1,8))
  8         print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11     test()
(Pdb) s
> /Users/yuichi/Scripts/test2.py(11)<module>()
-> test()
(Pdb) l
  6         print(divide(2,1))
  7         print(divide(1,8))
  8         print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11  -> test()
[EOF]

sだけでも何をやっているか表示をしてくれますので、毎回lを打つ必要はありません。今どこか詳細な確認をしたい場合のみ、lで確認すれば大丈夫です。続けて、どんどんstepしていきましょう。

(Pdb) s
--Call--
> /Users/yuichi/Scripts/test2.py(4)test()
-> def test():

関数testをCall(呼び出し) しましたね。続けます。

(Pdb) s
> /Users/yuichi/Scripts/test2.py(5)test()
-> print(divide(5,3))
(Pdb) l
  1     def divide(a, b):
  2         return a/b
  3
  4     def test():
  5  ->     print(divide(5,3))
  6         print(divide(2,1))
  7         print(divide(1,8))
  8         print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11     test()

関数の中に入りました。stepを続けます。

(Pdb) s
--Call--
> /Users/yuichi/Scripts/test2.py(1)divide()
-> def divide(a, b):
(Pdb) s
> /Users/yuichi/Scripts/test2.py(2)divide()
-> return a/b
(Pdb) s
--Return--
> /Users/yuichi/Scripts/test2.py(2)divide()->1
-> return a/b
(Pdb) s
1
> /Users/yuichi/Scripts/test2.py(6)test()
-> print(divide(2,1))

divide関数を呼び出し、最終的にreturnし、次のdivide(2,1)にまで進みましたね。毎回sですべての処理を呼ぶのも面倒なので、stepよりももう少し一気に進めるnextを使ってみます。

(Pdb) n
2
> /Users/yuichi/Scripts/test2.py(7)test()
-> print(divide(1,8))
(Pdb) n
0
> /Users/yuichi/Scripts/test2.py(8)test()
-> print(divide(4,0)) # BUG
(Pdb)

関数の中身を飛ばしています。sとnの表示の違いをよく見比べるとわかるはずです。続けてバグのある関数呼び出しもnextしてしまいます。

(Pdb) n
ZeroDivisionError: 'integer division or modulo by zero'
> /Users/yuichi/Scripts/test2.py(8)test()
-> print(divide(4,0)) # BUG

当然ながらエラーが表示されていますね。さて、stepとnextおよびlistがわかったところで新しいコマンドを使ってみます。ブレークポイントの設定breakと、breakポイントかエラーにヒットするまで進めるcontinue、そして変数の中身を確認するprintです。まず、一度デバッグをコマンドquitで抜けてしまいます。

(Pdb) q

# python -m pdb test2.py
> /Users/yuichi/Scripts/test2.py(1)<module>()
-> def divide(a, b):
(Pdb)

プログラムの場所を指定してブレークポイントをセットすると、そこまでデバッグプログラムを一気に進めてしまうことが可能です。今回は8行目からのdivide関数呼び出しでトラブルが発生しているので8行目にbreakをセットします。breakでブレークポイントをセットし、continueでブレークポイントまで一気に勧めます。

(Pdb) b 8
Breakpoint 1 at /Users/yuichi/Scripts/test2.py:8
(Pdb) c
1
2
0
> /Users/yuichi/Scripts/test2.py(8)test()
-> print(divide(4,0)) # BUG
(Pdb) l
  3
  4     def test():
  5         print(divide(5,3))
  6         print(divide(2,1))
  7         print(divide(1,8))
  8 B->     print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11     test()
[EOF]

さて、先程はnextで一気に勧めてしまったのですが、今度はstepで慎重に進めてみます。問題の箇所にきたら、printコマンドを使って変数の中身を見てみます。

(Pdb) s
--Call--
> /Users/yuichi/Scripts/test2.py(1)divide()
-> def divide(a, b):
(Pdb) s
> /Users/yuichi/Scripts/test2.py(2)divide()
-> return a/b
(Pdb) p a
4
(Pdb) p b
0

ZeroDivisionErrorの原因となった割り算の位置で、"p a"として変数aの中身を表示しています。bも同様です。bの値が0であることがわかり、これでなぜZeroDivisionErrorとなったかが詳細に確認できましたね。

なお、今回の例では多くのコマンドを割愛しています。それらについては以下を参照してください。

• 26.2. pdb - Python デバッガ

最後にpdb.set_trace()の使い方を説明します。先ほどは行番号を指定してbreakをセットしましたが、毎回この位置のコードをデバッグするのであればプログラム本文にブレークポイントを書くこともできます。

import pdb

def divide(a, b):
    return a/b

def test():
    print(divide(5,3))
    print(divide(2,1))
    print(divide(1,8))
    pdb.set_trace()
    print(divide(4,0)) # BUG
    print(divide(3,2))

test()

pdb.set_trace()がコード文中に設置されていますね。この状態で、シェルでデバッグしてみます。

python -m pdb test2.py
> /Users/yuichi/Scripts/test2.py(1)<module>()
-> import pdb
(Pdb) c
1
2
0
> /Users/yuichi/Scripts/test2.py(11)test()
-> print(divide(4,0)) # BUG
(Pdb)

continueすると、breakポイントをコマンドでセットしていなくても、このpdb.set_trace()したところで止まっていることがわかります。うまく使うことでデバッグ作業が楽になりますよ。

pdbを使ったクラッシュ後のデバッグ

先ほどはインタラクティブにプログラム起動時点からデバッグをしましたが、クラッシュ後にデバッグを開始することも可能です。まず、Pythonシェル(PDBのシェルとは違うので注意)に入って、先ほどのプログラムを実行してクラッシュさせます。

# python
>>> import test2
1
2
0
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "test2.py", line 11, in <module>
    test()
  File "test2.py", line 8, in test
    print(divide(4,0)) # BUG
  File "test2.py", line 2, in divide
    return a/b
ZeroDivisionError: integer division or modulo by zero

エラーが発生しましたね。ここで、pdbモジュールをロードしてpm()関数を実行してみます。

>>> import pdb
>>> pdb.pm()
> /Users/yuichi/Scripts/test2.py(2)divide()
-> return a/b
(Pdb)

PDBのシェルに入れましたね。先ほどの先頭から実行した場合と異なり、すでにクラッシュした行にいることがわかります。念のためにlistで確認します。

(Pdb) list
  1     def divide(a, b):
  2  ->     return a/b
  3
  4     def test():
  5         print(divide(5,3))
  6         print(divide(2,1))
  7         print(divide(1,8))
  8         print(divide(4,0)) # BUG
  9         print(divide(3,2))
 10
 11     test()
(Pdb) print a
4
(Pdb) print b
0

printを使って変数の中身も確認できています。ちなみに、stepやnextに対応する「戻る」はgdbとは違いサポートされていないようです。

---

次回は、Pythonの命名規則について扱います。

執筆者紹介 伊藤裕一(ITO Yuichi) シスコシステムズでの業務と大学での研究活動でコンピュータネットワークに6年関わる。専門はL2/L3 Switching とデータセンター関連技術およびSDN。TACとしてシスコ顧客のテクニカルサポート業務に従事。社内向けのソフトウェア関連のトレーニングおよびデータセンタとSDN関係の外部講演なども行う。 もともと仮想ネットワーク関連技術の研究開発に従事していたこともあり、ネットワークだけでなくプログラミングやLinux関連技術にも精通。Cisco社内外向けのトラブルシューティングツールの開発や、趣味で音声合成処理のアプリケーションやサービスを開発。 Cisco CCIE R&S, Red Hat Certified Engineer, Oracle Java Gold,2009年度 IPA 未踏プロジェクト採択 詳細(英語)はこちら